[ https://issues.apache.org/jira/browse/CLOUDSTACK-5484?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sangeetha Hariharan closed CLOUDSTACK-5484. ------------------------------------------- Tested by changing the value of vmware.vcenter.session.timeout to higher value. Now I am able to see the copy command can take more than 20 mts to complete. But after 1 hour , it times out with following exception: 2014-01-20 16:36:29,324 DEBUG [c.c.a.m.AgentAttache] (Job-Executor-1:ctx-f9b6eea3 ctx-d38166f5) Seq 2-1394540552: Waiting some more time because this is the current comman d 2014-01-20 16:36:29,325 INFO [c.c.u.e.CSExceptionErrorCode] (Job-Executor-1:ctx-f9b6eea3 ctx-d38166f5) Could not find exception: com.cloud.exception.OperationTimedoutExce ption in error code list for exceptions 2014-01-20 16:36:29,325 WARN [c.c.a.m.AgentAttache] (Job-Executor-1:ctx-f9b6eea3 ctx-d38166f5) Seq 2-1394540552: Timed out on Seq 2-1394540552: { Cmd , MgmtId: 953073548 44397, via: 2(10.223.57.4), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"p ath":"e5cbb1ad88f23fb6ad823102f2ce39e1","uuid":"b91e5323-3b39-4e15-b315-7d8afcd3736c","id":209,"format":"OVA","accountId":3,"hvm":true,"displayText":"9gb-tmp","imageDataSt ore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a0c555cc-695c-3343-bfa0-3413a91dbfed","id":1,"poolType":"NetworkFilesystem","host":"10.223.57.195","pa th":"/export/home/vmware/primary","port":2049,"url":"NetworkFilesystem://10.223.57.195//export/home/vmware/primary/?ROLE=Primary&STOREUUID=a0c555cc-695c-3343-bfa0-3413a91d bfed"}},"name":"226ed4516-fbfb-36f7-86bc-11978f842f69","hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"a1edafe3-ed2b-405d- 826c-4918663d4e91","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a0c555cc-695c-3343-bfa0-3413a91dbfed","id":1,"poolType": "NetworkFilesystem","host":"10.223.57.195","path":"/export/home/vmware/primary","port":2049,"url":"NetworkFilesystem://10.223.57.195//export/home/vmware/primary/?ROLE=Prim ary&STOREUUID=a0c555cc-695c-3343-bfa0-3413a91dbfed"}},"name":"ROOT-10","size":21474836480,"volumeId":10,"vmName":"i-2-10-MyTestVM","accountId":2,"format":"OVA","id":10,"de viceId":0,"hypervisorType":"VMware"}},"executeInSequence":false,"options":{},"wait":0}}] } 2014-01-20 16:36:29,326 DEBUG [o.a.c.s.RemoteHostEndPoint] (Job-Executor-1:ctx-f9b6eea3 ctx-d38166f5) Failed to send command, due to Agent:2, com.cloud.exception.Operation TimedoutException: Commands 1394540552 to Host 2 timed out after 3600 2014-01-20 16:36:29,326 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Job-Executor-1:ctx-f9b6eea3 ctx-d38166f5) Failed to send to storage pool com.cloud.utils.exception.CloudRuntimeException: Failed to send command, due to Agent:2, com.cloud.exception.OperationTimedoutException: Commands 1394540552 to Host 2 time d out after 3600 at org.apache.cloudstack.storage.RemoteHostEndPoint.sendMessage(RemoteHostEndPoint.java:116) at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.cloneVolume(AncientDataMotionStrategy.java:287) at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:415) at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:70) at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromBaseImageAsync(VolumeServiceImpl.java:544) at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:607) at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1171) at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1235) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:949) at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:752) at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:598) at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:228) at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:207) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3580) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3160) at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3146) 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:601) 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 com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) 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 $Proxy169.startVirtualMachine(Unknown Source) at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161) at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109) at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66) 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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:526) 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 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:722) Closing this issue since we are not timing out at vcenter sessions anymore. > Vmware - Not able to deploy Vm with template that is 20GB virtual size ( > actual size ~5gb). > ------------------------------------------------------------------------------------------- > > Key: CLOUDSTACK-5484 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5484 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Management Server > Affects Versions: 4.3.0 > Environment: Build from 4.3 > Reporter: Sangeetha Hariharan > Assignee: Likitha Shetty > Priority: Critical > Fix For: 4.3.0 > > > Deploy a Vm from a template that is 20GB virtual size ( actual size ~5gb). > Vm deployment fails. > > I see the following exception when executing “CopyCommand” : > > 2013-12-12 16:07:22,761 DEBUG [c.c.a.t.Request] (Job-Executor-27:ctx-df5f3257 > ctx-31077a83) Seq 1-2076837799: Executing: { Cmd , Mgm > tId: 95307354844397, via: 1(10.223.57.3), Ver: v1, Flags: 100011, > [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"or > g.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"a7ecc9e5798534608d3ae0dfe6da1c48","uuid":"0b5961cf-af11-4a19-a3d6-0858575ca > b40","id":205,"format":"OVA","accountId":2,"hvm":true,"displayText":"temp-10-gb-new","imageDataStore":{"org.apache.cloudstack.storage > .to.PrimaryDataStoreTO":{"uuid":"a0c555cc-695c-3343-bfa0-3413a91dbfed","id":1,"poolType":"NetworkFilesystem","host":"10.223.57.195"," > path":"/export/home/vmware/primary","port":2049,"url":"NetworkFilesystem://10.223.57.195//export/home/vmware/primary/?ROLE=Primary&ST > OREUUID=a0c555cc-695c-3343-bfa0-3413a91dbfed"}},"name":"275bf1387-d37d-31a9-9c65-fedcc79fdaf3","hypervisorType":"VMware"}},"destTO":{ > "org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"0cd27f84-c3e7-44d1-b2f7-5ada6cd8f679","volumeType":"ROOT","dataStore":{"or > g.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a0c555cc-695c-3343-bfa0-3413a91dbfed","id":1,"poolType":"NetworkFilesyste > m","host":"10.223.57.195","path":"/export/home/vmware/primary","port":2049,"url":"NetworkFilesystem://10.223.57.195//export/home/vmwa > re/primary/?ROLE=Primary&STOREUUID=a0c555cc-695c-3343-bfa0-3413a91dbfed"}},"name":"ROOT-12","size":21474836480,"volumeId":12,"vmName" > :"i-3-12-VM","accountId":3,"format":"OVA","id":12,"deviceId":0,"hypervisorType":"VMware"}},"executeInSequence":false,"wait":0}}] > } > > …… > > 2013-12-12 16:27:22,951 ERROR [c.c.s.r.VmwareStorageProcessor] > (DirectAgent-212:ctx-781beb3d 10.223.57.3) clone volume from base image fa > iled due to Exception: javax.xml.ws.WebServiceException > Message: java.net.SocketTimeoutException: Read timed out > > javax.xml.ws.WebServiceException: java.net.SocketTimeoutException: Read timed > out > at > com.sun.xml.internal.ws.transport.http.client.HttpClientTransport.readResponseCodeAndMessage(HttpClientTransport.java:196) > at > com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.createResponsePacket(HttpTransportPipe.java:212) > at > com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.process(HttpTransportPipe.java:203) > at > com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.processRequest(HttpTransportPipe.java:122) > at > com.sun.xml.internal.ws.transport.DeferredTransportPipe.processRequest(DeferredTransportPipe.java:95) > at com.sun.xml.internal.ws.api.pipe.Fiber.__doRun(Fiber.java:626) > at com.sun.xml.internal.ws.api.pipe.Fiber._doRun(Fiber.java:585) > at com.sun.xml.internal.ws.api.pipe.Fiber.doRun(Fiber.java:570) > at com.sun.xml.internal.ws.api.pipe.Fiber.runSync(Fiber.java:467) > at com.sun.xml.internal.ws.client.Stub.process(Stub.java:308) > at > com.sun.xml.internal.ws.client.sei.SEIStub.doProcess(SEIStub.java:146) > at > com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:98) > at > com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:78) > at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:129) > at $Proxy386.waitForUpdates(Unknown Source) > at > com.cloud.hypervisor.vmware.util.VmwareClient.waitForValues(VmwareClient.java:382) > at > com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:324) > at > com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createFullClone(VirtualMachineMO.java:606) > at > com.cloud.storage.resource.VmwareStorageProcessor.createVMFullClone(VmwareStorageProcessor.java:282) > at > com.cloud.storage.resource.VmwareStorageProcessor.cloneVolumeFromBaseTemplate(VmwareStorageProcessor.java:368) > at > com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:78) > at > com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155) > at > com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50 > ) > at > com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:553) > at > com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216) > 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 > 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$201(ScheduledThreadPoolExecutor.java:178) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) > 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:722) > Caused by: java.net.SocketTimeoutException: Read timed out > at java.net.SocketInputStream.socketRead0(Native Method) > at java.net.SocketInputStream.read(SocketInputStream.java:150) > at java.net.SocketInputStream.read(SocketInputStream.java:121) > at sun.security.ssl.InputRecord.readFully(InputRecord.java:312) > at sun.security.ssl.InputRecord.read(InputRecord.java:350) > at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:927) > at > sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:884) > at sun.security.ssl.AppInputStream.read(AppInputStream.java:102) > at java.io.BufferedInputStream.fill(BufferedInputStream.java:235) > at java.io.BufferedInputStream.read1(BufferedInputStream.java:275) > at java.io.BufferedInputStream.read(BufferedInputStream.java:334) > at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:633) > at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:579) > at > sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1322) > at > java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468) > at > sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:338) > at > com.sun.xml.internal.ws.transport.http.client.HttpClientTransport.readResponseCodeAndMessage(HttpClientTransport.java:192) > ... 37 more > 2013-12-12 16:27:22,955 DEBUG [c.c.a.m.DirectAgentAttache] > (DirectAgent-212:ctx-781beb3d) Seq 1-2076837799: Response Received: > 2013-12-12 16:27:22,955 DEBUG [c.c.a.t.Request] > (DirectAgent-212:ctx-781beb3d) Seq 1-2076837799: Processing: { Ans: , > MgmtId: 95307354844397, via: 1, Ver: v1, Flags: 10, > [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"javax.xml.ws.WebServiceException: > java.net.SocketTimeoutException: Read timed out","wait":0}}] } > 2013-12-12 16:27:22,955 DEBUG [c.c.a.t.Request] (Job-Executor-27:ctx-df5f3257 > ctx-31077a83) Seq 1-2076837799: Received: { Ans: , MgmtId: 95307354844397, > via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer } } > 2013-12-12 16:27:22,960 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] > (Job-Executor-27:ctx-df5f3257 ctx-31077a83) Unsupported data object (VOLUME, > org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@1353d0ab), no > need to delete from object in store ref table > 2013-12-12 16:27:22,961 INFO [o.a.c.s.v.VolumeServiceImpl] > (Job-Executor-27:ctx-df5f3257 ctx-31077a83) releasing lock for > VMTemplateStoragePool 15 > 2013-12-12 16:27:22,961 WARN [c.c.u.d.Merovingian2] > (Job-Executor-27:ctx-df5f3257 ctx-31077a83) Was unable to find lock for the > key template_spool_ref15 and thread id 1689517683 > 2013-12-12 16:27:22,961 DEBUG [o.a.c.e.o.VolumeOrchestrator] > (Job-Executor-27:ctx-df5f3257 ctx-31077a83) Unable to create > Vol[12|vm=12|ROOT]:javax.xml.ws.WebServiceException: > java.net.SocketTimeoutException: Read timed out > 2013-12-12 16:27:22,962 INFO [c.c.v.VirtualMachineManagerImpl] > (Job-Executor-27:ctx-df5f3257 ctx-31077a83) Unable to contact resource. > com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is > unreachable: Unable to create > Vol[12|vm=12|ROOT]:javax.xml.ws.WebServiceException: > java.net.SocketTimeoutException: Read timed out > at > org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1138) > at > org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1180) > at > com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:901) > at > com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:706) > at > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:552) > at > org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:228) > at > org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209) > at > com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3559) > at > com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3140) > at > com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3126) > 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:601) > 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 > com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) > 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 $Proxy170.startVirtualMachine(Unknown Source) > at > org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161) > at > com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109) > at > com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66) > at > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56) > -- This message was sent by Atlassian JIRA (v6.1.5#6160)