We can add virtual instances by iso and other templates which created by
cloudstack.
We want to migrate VMware instances to cloudstack.We import ova from
vcenter.And login in cloudstack,go to templates,click on register template.And
then add a instance by the template .But we can not add a new virtual instance
by the template.
Thank you very much.
w...@landhightech.com
From: Prashant Kumar Mishra
Date: 2015-01-09 16:42
To: users@cloudstack.apache.org
Subject: Re: Can not add a new virtual instance by a template
I am suspecting problem with the template ,check ssvm log can give you
details info . Can you check if template got copied properly may be try
to download it,check.Also make sure you are using service offering with
local storage enabled
Thanks
prashant
On 1/9/15, 1:26 PM, "w...@landhightech.com" <w...@landhightech.com> wrote:
>Hi，
>We had an issue when we add a new virtual instance by template.we can not
>create the new instance.
>We use cloudstack 4.4.1 + Vmware ,advanced network ,local storage.
>We want to add a new virtual instance into a share network.
>Message: File upload task failed to complete due to: Error writing
>request body to server
>
>------------------------------------------
>2015-01-09 23:30:14,876 DEBUG [o.a.c.s.RemoteHostEndPoint]
>(Timer-11:ctx-a09c3aac) Sending command
>org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3
>2015-01-09 23:30:14,878 DEBUG [c.c.a.t.Request] (Timer-11:ctx-a09c3aac)
>Seq 3-1751055830117010306: Sending { Cmd , MgmtId: 52230225403, via:
>3(s-1-VM), Ver: v1, Flags: 100011,
>[{"org.apache.cloudstack.storage.command.DownloadProgressCommand":{"jobId"
>:"b7835acd-50af-44e7-a91c-94b715722bfc","request":"GET_STATUS","hvm":false
>,"description":"CentOS 5.3(64-bit) no GUI
>(vSphere)","checksum":"f6f881b7f2292948d8494db837fe0f47","maxDownloadSizeI
>nBytes":53687091200,"id":7,"resourceType":"TEMPLATE","installPath":"templa
>te/tmpl/1/7","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.1
>68.10.2/secondary","_role":"Image"}},"url":"http://download.cloud.com/rele
>ases/2.2.0/CentOS5.3-x86_64.ova","format":"OVA","accountId":1,"name":"cent
>os53-x64","secUrl":"nfs://192.168.10.2/secondary","wait":0}}] }
>2015-01-09 23:30:14,923 DEBUG [c.c.a.t.Request]
>(AgentManager-Handler-11:null) Seq 3-1751055830117010306: Processing: {
>Ans: , MgmtId: 52230225403, via: 3, Ver: v1, Flags: 10,
>[{"com.cloud.agent.api.storage.DownloadAnswer":{"jobId":"b7835acd-50af-44e
>7-a91c-94b715722bfc","downloadPct":0,"errorString":"
>","downloadStatus":"DOWNLOAD_IN_PROGRESS","downloadPath":"/mnt/SecStorage/
>19e03beb-309a-3316-8e6d-5f25071372e5/template/tmpl/1/7/dnld504376175065878
>7860tmp_","installPath":"template/tmpl/1/7","templateSize":0,"templatePhyS
>icalSize":0,"checkSum":"f6f881b7f2292948d8494db837fe0f47","result":true,"d
>etails":" ","wait":0}}] }
>2015-01-09 23:30:15,780 DEBUG [c.c.a.ApiServlet]
>(catalina-exec-23:ctx-6e8835bf) ===START=== 192.168.255.102 -- GET
>command=queryAsyncJobResult&jobId=dde8c83e-63fc-4b49-b70d-27b3faca7883&res
>ponse=json&sessionkey=SST2qsGww2SbQBYEsnO7%2BoMlQWU%3D&_=1420788674854
>2015-01-09 23:30:15,841 DEBUG [c.c.a.ApiServlet]
>(catalina-exec-23:ctx-6e8835bf ctx-35fa8112) ===END=== 192.168.255.102 --
>GET
>command=queryAsyncJobResult&jobId=dde8c83e-63fc-4b49-b70d-27b3faca7883&res
>ponse=json&sessionkey=SST2qsGww2SbQBYEsnO7%2BoMlQWU%3D&_=1420788674854
>2015-01-09 23:30:16,170 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl]
>(Vm-Operations-Cleanup-1:ctx-86237200) Expunge completed work job-205
>2015-01-09 23:30:18,022 DEBUG [c.c.a.t.Request]
>(AgentManager-Handler-3:null) Seq 3-1751055830117010304: Processing: {
>Ans: , MgmtId: 52230225403, via: 3, Ver: v1, Flags: 10,
>[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"d
>etails":"Unable to copy template to primary storage due to
>exception:Exception: java.lang.Exception\nMessage: File upload task
>failed to complete due to: Error writing request body to
>server\n","wait":0}}] }
>2015-01-09 23:30:18,022 DEBUG [c.c.a.t.Request]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Seq
>3-1751055830117010304: Received: { Ans: , MgmtId: 52230225403, via: 3,
>Ver: v1, Flags: 10, { CopyCmdAnswer } }
>2015-01-09 23:30:18,047 DEBUG [c.c.a.m.AgentManagerImpl]
>(AgentManager-Handler-2:null) SeqA 2-22712: Processing Seq 2-22712: { Cmd
>, MgmtId: -1, via: 2, Ver: v1, Flags: 11,
>[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_lo
>adInfo":"{\n \"connections\": []\n}","wait":0}}] }
>2015-01-09 23:30:18,116 DEBUG [c.c.a.m.AgentManagerImpl]
>(AgentManager-Handler-2:null) SeqA 2-22712: Sending Seq 2-22712: { Ans: ,
>MgmtId: 52230225403, via: 2, Ver: v1, Flags: 100010,
>[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
>2015-01-09 23:30:18,150 INFO [o.a.c.s.v.VolumeServiceImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b)
>releasing lock for VMTemplateStoragePool 19
>2015-01-09 23:30:18,151 WARN [c.c.u.d.Merovingian2]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Was
>unable to find lock for the key template_spool_ref19 and thread id
>1216625438
>2015-01-09 23:30:18,151 DEBUG [o.a.c.e.o.VolumeOrchestrator]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Unable
>to create Vol[32|vm=27|ROOT]:Unable to copy template to primary storage
>due to exception:Exception: java.lang.Exception
>Message: File upload task failed to complete due to: Error writing
>request body to server
>
>2015-01-09 23:30:18,151 INFO [c.c.v.VirtualMachineManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Unable
>to contact resource.
>com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1]
>is unreachable: Unable to create Vol[32|vm=27|ROOT]:Unable to copy
>template to primary storage due to exception:Exception:
>java.lang.Exception
>Message: File upload task failed to complete due to: Error writing
>request body to server
>
>at
>org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolu
>me(VolumeOrchestrator.java:1205)
>at
>org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(Volu
>meOrchestrator.java:1257)
>at
>com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineMana
>gerImpl.java:988)
>at
>com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineMana
>gerImpl.java:5195)
>at sun.reflect.GeneratedMethodAccessor465.invoke(Unknown Source)
>at
>sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm
>pl.java:43)
>at java.lang.reflect.Method.invoke(Method.java:606)
>at
>com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.j
>ava:107)
>at
>com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManag
>erImpl.java:5340)
>at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
>at
>org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInConte
>xt(AsyncJobManagerImpl.java:503)
>at
>org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Managed
>ContextRunnable.java:49)
>at
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(De
>faultManagedContext.java:56)
>at
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithC
>ontext(DefaultManagedContext.java:103)
>at
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithCo
>ntext(DefaultManagedContext.java:53)
>at
>org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedCo
>ntextRunnable.java:46)
>at
>org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJ
>obManagerImpl.java:460)
>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)
>2015-01-09 23:30:18,190 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Cleaning
>up resources for the vm VM[User|i-2-27-VM] in Starting state
>2015-01-09 23:30:18,194 DEBUG [c.c.a.t.Request]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Seq
>1-5183080221150030303: Sending { Cmd , MgmtId: 52230225403, via:
>1(192.168.10.132), Ver: v1, Flags: 100011,
>[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":f
>alse,"checkBeforeCleanup":false,"vmName":"i-2-27-VM","wait":0}}] }
>2015-01-09 23:30:18,195 DEBUG [c.c.a.t.Request]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Seq
>1-5183080221150030303: Executing: { Cmd , MgmtId: 52230225403, via:
>1(192.168.10.132), Ver: v1, Flags: 100011,
>[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":f
>alse,"checkBeforeCleanup":false,"vmName":"i-2-27-VM","wait":0}}] }
>2015-01-09 23:30:18,195 DEBUG [c.c.a.m.DirectAgentAttache]
>(DirectAgent-180:ctx-c474087e) Seq 1-5183080221150030303: Executing
>request
>2015-01-09 23:30:18,196 INFO [c.c.h.v.r.VmwareResource]
>(DirectAgent-180:ctx-c474087e 192.168.10.132) Executing resource
>StopCommand:
>{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmN
>ame":"i-2-27-VM","wait":0}
>2015-01-09 23:30:18,216 DEBUG [c.c.h.v.m.HostMO]
>(DirectAgent-180:ctx-c474087e 192.168.10.132) find VM i-2-27-VM on host
>2015-01-09 23:30:18,217 INFO [c.c.h.v.m.HostMO]
>(DirectAgent-180:ctx-c474087e 192.168.10.132) VM i-2-27-VM not found in
>host cache
>2015-01-09 23:30:18,217 DEBUG [c.c.h.v.m.HostMO]
>(DirectAgent-180:ctx-c474087e 192.168.10.132) load VM cache on host
>2015-01-09 23:30:18,248 INFO [c.c.h.v.r.VmwareResource]
>(DirectAgent-180:ctx-c474087e 192.168.10.132) VM i-2-27-VM is no longer
>in vSphere
>2015-01-09 23:30:18,249 DEBUG [c.c.a.m.DirectAgentAttache]
>(DirectAgent-180:ctx-c474087e) Seq 1-5183080221150030303: Response
>Received:
>2015-01-09 23:30:18,249 DEBUG [c.c.a.t.Request]
>(DirectAgent-180:ctx-c474087e) Seq 1-5183080221150030303: Processing: {
>Ans: , MgmtId: 52230225403, via: 1, Ver: v1, Flags: 10,
>[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM i-2-27-VM
>is no longer in vSphere","wait":0}}] }
>2015-01-09 23:30:18,249 DEBUG [c.c.a.t.Request]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Seq
>1-5183080221150030303: Received: { Ans: , MgmtId: 52230225403, via: 1,
>Ver: v1, Flags: 10, { StopAnswer } }
>2015-01-09 23:30:18,259 DEBUG [o.a.c.e.o.NetworkOrchestrator]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Changing
>active number of nics for network id=205 on -1
>2015-01-09 23:30:18,289 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b)
>Successfully released network resources for the vm VM[User|i-2-27-VM]
>2015-01-09 23:30:18,290 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b)
>Successfully cleanued up resources for the vm VM[User|i-2-27-VM] in
>Starting state
>2015-01-09 23:30:18,303 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Deploy
>avoids pods: [], clusters: [], hosts: [1]
>2015-01-09 23:30:18,305 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b)
>DeploymentPlanner allocation algorithm:
>com.cloud.deploy.FirstFitPlanner@47130493
>2015-01-09 23:30:18,305 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Trying
>to allocate a host and storage pools from dc:1, pod:1,cluster:1,
>requested cpu: 1999, requested ram: 2147483648
>2015-01-09 23:30:18,305 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Is ROOT
>volume READY (pool already allocated)?: No
>2015-01-09 23:30:18,305 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b)
>DeploymentPlan has host_id specified, choosing this host and making no
>checks on this host: 1
>2015-01-09 23:30:18,307 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) The
>specified host is in avoid set
>2015-01-09 23:30:18,307 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Cannnot
>deploy to specified host, returning.
>2015-01-09 23:30:18,404 DEBUG [c.c.c.CapacityManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) VM state
>transitted from :Starting to Stopped with event: OperationFailedvm's
>original host id: null new host id: null host id before state transition:
>1
>2015-01-09 23:30:18,413 DEBUG [c.c.c.CapacityManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Hosts's
>actual total CPU: 31984 and CPU after applying overprovisioning: 31984
>2015-01-09 23:30:18,413 DEBUG [c.c.c.CapacityManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Hosts's
>actual total RAM: 137357598720 and RAM after applying overprovisioning:
>137357598720
>2015-01-09 23:30:18,413 DEBUG [c.c.c.CapacityManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) release
>cpu from host: 1, old used: 13994,reserved: 1999, actual total: 31984,
>total with overprovisioning: 31984; new used: 11995,reserved:1999;
>movedfromreserved: false,moveToReserveredfalse
>2015-01-09 23:30:18,413 DEBUG [c.c.c.CapacityManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) release
>mem from host: 1, old used: 14763950080,reserved: 2147483648, total:
>137357598720; new used: 12616466432,reserved:2147483648;
>movedfromreserved: false,moveToReserveredfalse
>2015-01-09 23:30:18,481 ERROR [c.c.v.VmWorkJobHandlerProxy]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b)
>Invocation exception, caused by:
>com.cloud.exception.InsufficientServerCapacityException: Unable to create
>a deployment for VM[User|i-2-27-VM]Scope=interface
>com.cloud.dc.DataCenter; id=1
>2015-01-09 23:30:18,481 INFO [c.c.v.VmWorkJobHandlerProxy]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207 ctx-be9a377b) Rethrow
>exception com.cloud.exception.InsufficientServerCapacityException: Unable
>to create a deployment for VM[User|i-2-27-VM]Scope=interface
>com.cloud.dc.DataCenter; id=1
>2015-01-09 23:30:18,482 DEBUG [c.c.v.VmWorkJobDispatcher]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) Done with run of VM
>work job: com.cloud.vm.VmWorkStart for VM 27, job origin: 206
>2015-01-09 23:30:18,482 ERROR [c.c.v.VmWorkJobDispatcher]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) Unable to complete
>AsyncJobVO {id:207, userId: 2, accountId: 2, instanceType: null,
>instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
>rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm
>9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtM
>AAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTm
>FtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFu
>bmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS
>91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-Z
>tlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AA
>N4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAG3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA
>AAAAAAAAAXBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubG
>FuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAAFxAH4ACnBwcHEAfgAKcHNyABFqYXZhLnV0
>aWwuSGFzaE1hcAUH2sHDFmDRAwACRgAKbG9hZEZhY3RvckkACXRocmVzaG9sZHhwP0AAAAAAAA
>x3CAAAABAAAAABdAAKVm1QYXNzd29yZHQAHHJPMEFCWFFBRG5OaGRtVmtYM0JoYzNOM2IzSmt4
>cA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
>result: null, initMsid: 52230225403, completeMsid: null, lastUpdated:
>null, lastPolled: null, created: Fri Jan 09 23:30:09 CST 2015}, job
>origin:206
>com.cloud.exception.InsufficientServerCapacityException: Unable to create
>a deployment for VM[User|i-2-27-VM]Scope=interface
>com.cloud.dc.DataCenter; id=1
>at
>com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineMana
>gerImpl.java:947)
>at
>com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineMana
>gerImpl.java:5195)
>at sun.reflect.GeneratedMethodAccessor465.invoke(Unknown Source)
>at
>sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm
>pl.java:43)
>at java.lang.reflect.Method.invoke(Method.java:606)
>at
>com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.j
>ava:107)
>at
>com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManag
>erImpl.java:5340)
>at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
>at
>org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInConte
>xt(AsyncJobManagerImpl.java:503)
>at
>org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Managed
>ContextRunnable.java:49)
>at
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(De
>faultManagedContext.java:56)
>at
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithC
>ontext(DefaultManagedContext.java:103)
>at
>org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithCo
>ntext(DefaultManagedContext.java:53)
>at
>org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedCo
>ntextRunnable.java:46)
>at
>org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJ
>obManagerImpl.java:460)
>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)
>2015-01-09 23:30:18,485 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) Complete async
>job-207, jobStatus: FAILED, resultCode: 0, result:
>rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubG
>FuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsD
>AARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMam
>F2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVs
>ZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3
>QAUEpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBVbmFibGUgdG8gY3JlYXRlIGEgZGVwbG95
>bWVudCBmb3IgVk1bVXNlcnxpLTItMjctVk1ddXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbG
>VtZW50OwJGKjw8_SI5AgAAeHAAAAANc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJ
>xZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AARMAAhmaWxlTmFtZX
>EAfgAETAAKbWV0aG9kTmFtZXEAfgAEeHAAAABydAAgY29tLmNsb3VkLnZtLlZtV29ya0pvYkRp
>c3BhdGNoZXJ0ABhWbVdvcmtKb2JEaXNwYXRjaGVyLmphdmF0AAZydW5Kb2JzcQB-AAsAAAH3dA
>A_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5h
>Z2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0c3EAfg
>ALAAAAMXQAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENv
>bnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVuc3EAfg
>ALAAAAOHQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZh
>dWx0TWFuYWdlZENvbnRleHQkMXQAGkRlZmF1bHRNYW5hZ2VkQ29udGV4dC5qYXZhdAAEY2FsbH
>NxAH4ACwAAAGd0AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwu
>RGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-ABp0AA9jYWxsV2l0aENvbnRleHRzcQB-AAsAAAA1cQ
>B-AB1xAH4AGnQADnJ1bldpdGhDb250ZXh0c3EAfgALAAAALnQAPG9yZy5hcGFjaGUuY2xvdWRz
>dGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZXEAfgAWcQB-ABdzcQ
>B-AAsAAAHMcQB-ABFxAH4AEnEAfgAXc3EAfgALAAAB13QALmphdmEudXRpbC5jb25jdXJyZW50
>LkV4ZWN1dG9ycyRSdW5uYWJsZUFkYXB0ZXJ0AA5FeGVjdXRvcnMuamF2YXEAfgAbc3EAfgALAA
>ABBnQAH2phdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2t0AA9GdXR1cmVUYXNrLmphdmFx
>AH4AF3NxAH4ACwAABHl0ACdqYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3
>J0ABdUaHJlYWRQb29sRXhlY3V0b3IuamF2YXQACXJ1bldvcmtlcnNxAH4ACwAAAmd0AC5qYXZh
>LnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IkV29ya2VycQB-ACxxAH4AF3NxAH
>4ACwAAAul0ABBqYXZhLmxhbmcuVGhyZWFkdAALVGhyZWFkLmphdmFxAH4AF3NyACZqYXZhLnV0
>aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlTGlzdPwPJTG17I4QAgABTAAEbGlzdHEAfgAGeH
>IALGphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVDb2xsZWN0aW9uGUIAgMte9x4C
>AAFMAAFjdAAWTGphdmEvdXRpbC9Db2xsZWN0aW9uO3hwc3IAE2phdmEudXRpbC5BcnJheUxpc3
>R4gdIdmcdhnQMAAUkABHNpemV4cAAAAAB3BAAAAAB4cQB-ADh4
>2015-01-09 23:30:18,525 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) Done executing
>com.cloud.vm.VmWorkStart for job-207
>2015-01-09 23:30:18,570 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(API-Job-Executor-101:ctx-22f197b7 job-206 ctx-49df178b) Sync job-208
>execution on object VmWorkJobQueue.27
>2015-01-09 23:30:18,574 WARN [c.c.u.d.Merovingian2]
>(API-Job-Executor-101:ctx-22f197b7 job-206 ctx-49df178b) Was unable to
>find lock for the key vm_instance27 and thread id 1208656886
>2015-01-09 23:30:18,691 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) Executing sync queue
>item: SyncQueueItemVO {id:93, queueId: 92, contentType: AsyncJob,
>contentId: 208, lastProcessMsid: 52230225403, lastprocessNumber: 2,
>lastProcessTime: Fri Jan 09 23:30:18 CST 2015, created: Fri Jan 09
>23:30:18 CST 2015}
>2015-01-09 23:30:18,693 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) Schedule queued
>job-208
>2015-01-09 23:30:18,756 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) Queue (queue id, sync
>type, sync id) - (92,VmWorkJobQueue, 27) is reaching concurrency limit 1
>2015-01-09 23:30:18,756 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) There is a pending
>process in sync queue(id: 92)
>2015-01-09 23:30:18,757 INFO [o.a.c.f.j.i.AsyncJobMonitor]
>(Work-Job-Executor-92:ctx-cf7cb5f7 job-206/job-207) Remove job-207 from
>job monitoring
>2015-01-09 23:30:18,760 INFO [o.a.c.f.j.i.AsyncJobMonitor]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208) Add job-208 into job
>monitoring
>2015-01-09 23:30:18,760 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208) Executing AsyncJobVO
>{id:208, userId: 2, accountId: 2, instanceType: null, instanceId: null,
>cmd: com.cloud.vm.VmWorkStart, cmdInfo:
>rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm
>9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtM
>AAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTm
>FtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFu
>bmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS
>91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-Z
>tlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AA
>N4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAG3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA
>AAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRm
>FjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AApWbVBhc3N3b3JkdAAcck8w
>QUJYUUFEbk5oZG1Wa1gzQmhjM04zYjNKa3hw, cmdVersion: 0, status: IN_PROGRESS,
>processStatus: 0, resultCode: 0, result: null, initMsid: 52230225403,
>completeMsid: null, lastUpdated: null, lastPolled: null, created: Fri Jan
>09 23:30:18 CST 2015}
>2015-01-09 23:30:18,761 DEBUG [c.c.v.VmWorkJobDispatcher]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208) Run VM work job:
>com.cloud.vm.VmWorkStart for VM 27, job origin: 206
>2015-01-09 23:30:18,763 DEBUG [c.c.v.VmWorkJobHandlerProxy]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208 ctx-a48025cb) Execute
>VM work job:
>com.cloud.vm.VmWorkStart{"dcId":0,"rawParams":{"VmPassword":"rO0ABXQADnNhd
>mVkX3Bhc3N3b3Jk"},"userId":2,"accountId":2,"vmId":27,"handlerName":"Virtua
>lMachineManagerImpl"}
>2015-01-09 23:30:18,774 DEBUG [c.c.c.CapacityManagerImpl]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208 ctx-a48025cb) VM state
>transitted from :Stopped to Starting with event: StartRequestedvm's
>original host id: null new host id: null host id before state transition:
>null
>2015-01-09 23:30:18,774 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208 ctx-a48025cb)
>Successfully transitioned to start state for VM[User|i-2-27-VM]
>reservation id = b7635084-3b16-421f-9049-60c455b23867
>2015-01-09 23:30:18,785 DEBUG [c.c.a.ApiServlet]
>(catalina-exec-24:ctx-d4c2aaff) ===START=== 192.168.255.102 -- GET
>command=queryAsyncJobResult&jobId=dde8c83e-63fc-4b49-b70d-27b3faca7883&res
>ponse=json&sessionkey=SST2qsGww2SbQBYEsnO7%2BoMlQWU%3D&_=1420788677859
>2015-01-09 23:30:18,828 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208 ctx-a48025cb) Trying
>to deploy VM, vm has dcId: 1 and podId: 1
>2015-01-09 23:30:18,828 DEBUG [c.c.v.VirtualMachineManagerImpl]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208 ctx-a48025cb) Deploy
>avoids pods: null, clusters: null, hosts: null
>2015-01-09 23:30:18,843 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208 ctx-a48025cb) Deploy
>avoids pods: [], clusters: [], hosts: []
>2015-01-09 23:30:18,844 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
>(Work-Job-Executor-93:ctx-69a2c541 job-206/job-208 ctx-a48025cb)
>DeploymentPlanner allocation algorithm:
>com.cloud.deploy.FirstFitPlanner@47130493
>
>Thanks.
>
>
>
>w...@landhightech.com
