manasaveloori created CLOUDSTACK-4517:
-----------------------------------------
Summary: [upgrade][Vmware]Deployment of VM using template
registered before upgrade is failing.
Key: CLOUDSTACK-4517
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4517
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Upgrade, VMware
Affects Versions: 4.2.0
Environment: upgraded from 3.07 to 4.2
Reporter: manasaveloori
Priority: Critical
Fix For: 4.2.1
Attachments: management-server.zip, mysqldumpAfterUp.dmp,
mysqldumpBeforeUp.dmp
Steps:
1. Have CS with 3.0.7 build.
2. Register a template
id: 10
store_id: 2
template_id: 204
created: 2013-08-27 12:13:34
last_updated: 2013-08-27 16:05:45
job_id: e7c32b26-3e06-4a9e-a9d0-cd6452595659
download_pct: 100
size: 107374182400
store_role: Image
physical_size: 707778560
download_state: DOWNLOADED
error_str: Install completed successfully at 8/27/13 6:54 AM
local_path:
/mnt/SecStorage/0e8da06e-0788-3efb-86a6-b0705a2205d3/template/tmpl/2/204/dnld4711105428993449674tmp_
install_path:
template/tmpl/2/204/dec94d02-8c40-34e8-9a1d-99906a95df2a.ova
url: http://10.147.28.7/templates/vmware/Centos6_2.ova
download_url: NULL
download_url_created: NULL
state: Ready
destroyed: 0
is_copy: 0
update_count: 0
ref_cnt: 0
updated: NULL
5 rows in set (0.00 sec)
3. Upgrade the build to 4.2.
4. Deploy a VM using the template registered before upgrade.
Observation:
Observed the following exception:
2013-08-27 23:08:37,892 ERROR [storage.resource.VmwareStorageProcessor]
(DirectAgent-101: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:201)
at
com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.process(HttpTransportPipe.java:151)
at
com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.processRequest(HttpTransportPipe.java:83)
at
com.sun.xml.internal.ws.transport.DeferredTransportPipe.processRequest(DeferredTransportPipe.java:78)
at com.sun.xml.internal.ws.api.pipe.Fiber.__doRun(Fiber.java:587)
at com.sun.xml.internal.ws.api.pipe.Fiber._doRun(Fiber.java:546)
at com.sun.xml.internal.ws.api.pipe.Fiber.doRun(Fiber.java:531)
at com.sun.xml.internal.ws.api.pipe.Fiber.runSync(Fiber.java:428)
at com.sun.xml.internal.ws.client.Stub.process(Stub.java:211)
at
com.sun.xml.internal.ws.client.sei.SEIStub.doProcess(SEIStub.java:124)
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:107)
at $Proxy90.waitForUpdates(Unknown Source)
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForValues(VmwareClient.java:428)
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:371)
at
com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createFullClone(VirtualMachineMO.java:594)
at
com.cloud.storage.resource.VmwareStorageProcessor.createVMFullClone(VmwareStorageProcessor.java:293)
at
com.cloud.storage.resource.VmwareStorageProcessor.cloneVolumeFromBaseTemplate(VmwareStorageProcessor.java:384)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:73)
at
com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:147)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:561)
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)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:146)
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:850)
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:807)
at sun.security.ssl.AppInputStream.read(AppInputStream.java:94)
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:688)
at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:633)
at
sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1162)
at
java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:397)
at
sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:338)
at
com.sun.xml.internal.ws.transport.http.client.HttpClientTransport.readResponseCodeAndMessage(HttpClientTransport.java:198)
... 31 more
2013-08-27 23:08:37,897 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-101:null) Seq 1-2035483031: Response Received:
2013-08-27 23:08:37,898 DEBUG [agent.transport.Request] (DirectAgent-101:null)
Seq 1-2035483031: Processing: { Ans: , MgmtId: 7067804893289, 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-08-27 23:08:37,898 DEBUG [agent.transport.Request] (Job-Executor-21:job-70
= [ 90846de9-2058-43d5-accc-b71b5b14eea3 ]) Seq 1-2035483031: Received: { Ans:
, MgmtId: 7067804893289, via: 1, Ver: v1, Flags: 110, { CopyCmdAnswer } }
2013-08-27 23:08:37,902 DEBUG [agent.manager.AgentAttache]
(DirectAgent-101:null) Seq 1-2035483031: No more commands found
2013-08-27 23:08:37,917 WARN [storage.datastore.ObjectInDataStoreManagerImpl]
(Job-Executor-21:job-70 = [ 90846de9-2058-43d5-accc-b71b5b14eea3 ]) Unsupported
data object (VOLUME,
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@2dea05d5), no need
to delete from object in store ref table
2013-08-27 23:08:37,918 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-21:job-70 = [ 90846de9-2058-43d5-accc-b71b5b14eea3 ]) Unable to
create Vol[30|vm=12|ROOT]:javax.xml.ws.WebServiceException:
java.net.SocketTimeoutException: Read timed out
2013-08-27 23:08:37,918 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-21:job-70 = [ 90846de9-2058-43d5-accc-b71b5b14eea3 ]) Unable to
contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:201] is
unreachable: Unable to create
Vol[30|vm=12|ROOT]:javax.xml.ws.WebServiceException:
java.net.SocketTimeoutException: Read timed out
at
com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2534)
at
com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2582)
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-08-27 23:08:37,926 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-21:job-70 = [ 90846de9-2058-43d5-accc-b71b5b14eea3 ]) Cleaning up
resources for the vm VM[User|tempBUVmShared] in Starting state
2013-08-27 23:08:37,931 DEBUG [agent.transport.Request] (Job-Executor-21:job-70
= [ 90846de9-2058-43d5-accc-b71b5b14eea3 ]) Seq 1-2035483080: Sending { Cmd ,
MgmtId: 7067804893289, via: 1, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-12-VM","wait":0}}]
}
Attaching the Logs and DB dumps
--
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
