You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cloudstack.apache.org by Denis Finko <de...@ecommerce.com> on 2014/07/29 10:42:25 UTC
'Read timed out' issue
Hello CloudStack Developers,
Could you please help me to investigate or understand following issue with time out:
When I am creating new VMs from CloudStack template with large storage size and if 'Clone virtual machine' in VMware takes more that 20 min CloudStack can't provision this VM and show following error:
Start cloning new VM:
2014-07-25 08:02:55,419 DEBUG [agent.manager.ClusteredAgentAttache] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Seq 4-421602206: Forwarding Seq 4-421602206: { Cmd , MgmtId: 345048632606, via: 4, Ver: v1, Flags: 100111,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"abc3a4f5f06634c890e8364f97b0380d","origUrl":"http://mydomain.com/WS12R2-I-MY5MS12S-0.ova","uuid":"c44d5426-4b07-4dc3-b925-4fc36dfcc175","id":632,"format":"OVA","accountId":2,"checksum":"78af69cd4c13694a36f605d035aa8a34","hvm":true,"displayText":"Microsoft
Windows Server 2012 R2 featuring Internet Information Services (IIS) 8.5, MSSQL 2012 Standard Edition and MySQL 5.x without the overhead of a control
panel.","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a419f8f4-6511-3e15-aabf-44578f6c1b8f","id":3,"poolType":"VMFS","host":"VMFS datastore: /DS/AUTO1","path":"/DS/
AUTO1","port":0}},"name":"632-2-cebb1554-b755-3197-b636-b43648f36554","hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"5f5a9b6c-6e51-4837-91c9-9844a1e6f0cc","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a419f8f4-6511-3e15-aabf-44578f6c1b8f","id":3,"poolType":"VMFS","host":"VMFS
datastore: /DS/AUTO1","path":"/DS/AUTO1","port":0}},"name":"ROOT-1265","size":42949672960,"volumeId":1319,"vmName":"i-43-1265-VM","accountId":43,"format":"OVA","id":1319,"hypervisorType":"VMware"}},"executeInSequence":true,"wait":0}}] } to 345048630655
After 20 minutes:
2014-07-25 08:22:55,965 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 4-421602206: Processing: { Ans: , MgmtId: 345048632606, via: 4, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"javax.xml.ws.WebServiceException:
java.net.SocketTimeoutException: Read timed out","wait":0}}] }
2014-07-25 08:22:55,974 WARN [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@33a78d5c), no need to delete from object in store ref table
2014-07-25 08:22:55,975 INFO [storage.volume.VolumeServiceImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) releasing lock for VMTemplateStoragePool 4102
2014-07-25 08:22:55,976 WARN [utils.db.Merovingian2] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Was unable to find lock for the key template_spool_ref4102 and thread id 611898505
2014-07-25 08:22:55,976 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Unable to create Vol[1319|vm=1265|ROOT]:javax.xml.ws.WebServiceException: java.net.SocketTimeoutException: Read timed out
2014-07-25 08:22:55,976 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:3] is unreachable: Unable to create Vol[1319|vm=1265|ROOT]:javax.xml.ws.WebServiceException: java.net.SocketTimeoutException: Read timed out
at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2629)
at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2680)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:958)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:647)
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:3588)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3107)
at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3093)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:437)
at com.ds.cloud.api.DeployVMWithIpRangeCmd.execute(DeployVMWithIpRangeCmd.java:85)
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-25 08:22:55,982 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Cleaning up resources for the vm VM[User|DB7-WS12R2-I-MY5MS12S-0] in Starting state
I have checked all Global Settings in CloudStack side and haven't found limit that can be responsible for this and equal to 20 minutes.
Thank you!
Re: 'Read timed out' issue
Posted by ilya musayev <il...@gmail.com>.
Denis
You havent mentioned anything about your setup and CloudStack version.
Regards,
ilya
On 7/29/14, 1:42 AM, Denis Finko wrote:
> Hello CloudStack Developers,
>
> Could you please help me to investigate or understand following issue with time out:
>
> When I am creating new VMs from CloudStack template with large storage size and if 'Clone virtual machine' in VMware takes more that 20 min CloudStack can't provision this VM and show following error:
>
> Start cloning new VM:
> 2014-07-25 08:02:55,419 DEBUG [agent.manager.ClusteredAgentAttache] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Seq 4-421602206: Forwarding Seq 4-421602206: { Cmd , MgmtId: 345048632606, via: 4, Ver: v1, Flags: 100111,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"abc3a4f5f06634c890e8364f97b0380d","origUrl":"http://mydomain.com/WS12R2-I-MY5MS12S-0.ova","uuid":"c44d5426-4b07-4dc3-b925-4fc36dfcc175","id":632,"format":"OVA","accountId":2,"checksum":"78af69cd4c13694a36f605d035aa8a34","hvm":true,"displayText":"Microsoft
> Windows Server 2012 R2 featuring Internet Information Services (IIS) 8.5, MSSQL 2012 Standard Edition and MySQL 5.x without the overhead of a control
> panel.","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a419f8f4-6511-3e15-aabf-44578f6c1b8f","id":3,"poolType":"VMFS","host":"VMFS datastore: /DS/AUTO1","path":"/DS/
> AUTO1","port":0}},"name":"632-2-cebb1554-b755-3197-b636-b43648f36554","hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"5f5a9b6c-6e51-4837-91c9-9844a1e6f0cc","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a419f8f4-6511-3e15-aabf-44578f6c1b8f","id":3,"poolType":"VMFS","host":"VMFS
> datastore: /DS/AUTO1","path":"/DS/AUTO1","port":0}},"name":"ROOT-1265","size":42949672960,"volumeId":1319,"vmName":"i-43-1265-VM","accountId":43,"format":"OVA","id":1319,"hypervisorType":"VMware"}},"executeInSequence":true,"wait":0}}] } to 345048630655
>
> After 20 minutes:
> 2014-07-25 08:22:55,965 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 4-421602206: Processing: { Ans: , MgmtId: 345048632606, via: 4, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"javax.xml.ws.WebServiceException:
> java.net.SocketTimeoutException: Read timed out","wait":0}}] }
>
> 2014-07-25 08:22:55,974 WARN [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@33a78d5c), no need to delete from object in store ref table
> 2014-07-25 08:22:55,975 INFO [storage.volume.VolumeServiceImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) releasing lock for VMTemplateStoragePool 4102
> 2014-07-25 08:22:55,976 WARN [utils.db.Merovingian2] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Was unable to find lock for the key template_spool_ref4102 and thread id 611898505
> 2014-07-25 08:22:55,976 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Unable to create Vol[1319|vm=1265|ROOT]:javax.xml.ws.WebServiceException: java.net.SocketTimeoutException: Read timed out
> 2014-07-25 08:22:55,976 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Unable to contact resource.
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:3] is unreachable: Unable to create Vol[1319|vm=1265|ROOT]:javax.xml.ws.WebServiceException: java.net.SocketTimeoutException: Read timed out
> at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2629)
> at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2680)
> at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:958)
> at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:647)
> 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:3588)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3107)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3093)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:437)
> at com.ds.cloud.api.DeployVMWithIpRangeCmd.execute(DeployVMWithIpRangeCmd.java:85)
> 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-25 08:22:55,982 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-107:job-3742 = [ aca3b27c-3ef8-46ed-9542-3148dd055533 ]) Cleaning up resources for the vm VM[User|DB7-WS12R2-I-MY5MS12S-0] in Starting state
>
> I have checked all Global Settings in CloudStack side and haven't found limit that can be responsible for this and equal to 20 minutes.
>
> Thank you!
>
>