manasaveloori created CLOUDSTACK-5041:
-----------------------------------------
Summary: [upgrade]VM deployment using the template registered
before upgrade is failing with java.net.SocketTimeoutException
Key: CLOUDSTACK-5041
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5041
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Upgrade, VMware
Affects Versions: 4.2.1
Environment: upgrade from 4.2 to 4.2.1 using VMware HV
Reporter: manasaveloori
Priority: Blocker
Fix For: 4.2.1
1. Have CS 4.2 with VMware HV.
2. register a template centos.
3. upgrade to 4.2.1
4. Deploy a VM using the template registered before upgrade.
Observation:
Observed the following exception:
ERROR [storage.resource.VmwareStorageProcessor] (DirectAgent-95:10.147.40.28)
clone volume from base image failed 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 $Proxy90.waitForUpdates(Unknown Source)
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForValues(VmwareClient.java:462)
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:404)
at
com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createFullClone(VirtualMachineMO.java:602)
at
com.cloud.storage.resource.VmwareStorageProcessor.createVMFullClone(VmwareStorageProcessor.java:296)
at
com.cloud.storage.resource.VmwareStorageProcessor.cloneVolumeFromBaseTemplate(VmwareStorageProcessor.java:382)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:73)
at
com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:559)
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$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)
... 32 more
2013-11-05 10:48:14,902 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-95:null) Seq 1-217317557: Response Received:
2013-11-05 10:48:14,904 DEBUG [agent.transport.Request] (DirectAgent-95:null)
Seq 1-217317557: Processing: { Ans: , MgmtId: 6758231703598, via: 1, 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}}] }
2013-11-05 10:48:14,904 DEBUG [agent.transport.Request] (Job-Executor-12:job-55
= [ de037e5f-78c9-4d8a-986b-6944511d9afc ]) Seq 1-217317557: Received: { Ans:
, MgmtId: 6758231703598, via: 1, Ver: v1, Flags: 110, { CopyCmdAnswer } }
2013-11-05 10:48:14,908 DEBUG [agent.manager.AgentAttache]
(DirectAgent-95:null) Seq 1-217317557: No more commands found
2013-11-05 10:48:14,938 WARN [storage.datastore.ObjectInDataStoreManagerImpl]
(Job-Executor-12:job-55 = [ de037e5f-78c9-4d8a-986b-6944511d9afc ]) Unsupported
data object (VOLUME,
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@31b9901d), no need
to delete from object in store ref table
2013-11-05 10:48:14,946 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-12:job-55 = [ de037e5f-78c9-4d8a-986b-6944511d9afc ]) Unable to
create Vol[17|vm=13|ROOT]:javax.xml.ws.WebServiceException:
java.net.SocketTimeoutException: Read timed out
2013-11-05 10:48:14,946 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-12:job-55 = [ de037e5f-78c9-4d8a-986b-6944511d9afc ]) Unable to
contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is
unreachable: Unable to create
Vol[17|vm=13|ROOT]:javax.xml.ws.WebServiceException:
java.net.SocketTimeoutException: Read timed out
at
com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2580)
at
com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2631)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
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:3440)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3000)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2986)
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:722)
2013-11-05 10:48:14,961 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-12:job-55 = [ de037e5f-78c9-4d8a-986b-6944511d9afc ]) Cleaning up
resources for the vm VM[User|3f8a946f-eef1-4b25-a0a3-985e57525c42] in Starting
state
2013-11-05 10:48:14,964 DEBUG [agent.transport.Request] (Job-Executor-12:job-55
= [ de037e5f-78c9-4d8
--
This message was sent by Atlassian JIRA
(v6.1#6144)
