cloudstack-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Wwei@landhightech.com" <W...@landhightech.com>
Subject Can not add a new virtual instance by a template
Date Fri, 09 Jan 2015 08:17:06 GMT
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","maxDownloadSizeInBytes":53687091200,"id":7,"resourceType":"TEMPLATE","installPath":"template/tmpl/1/7","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.10.2/secondary","_role":"Image"}},"url":"http://download.cloud.com/releases/2.2.0/CentOS5.3-x86_64.ova","format":"OVA","accountId":1,"name":"centos53-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-44e7-a91c-94b715722bfc","downloadPct":0,"errorString":"
","downloadStatus":"DOWNLOAD_IN_PROGRESS","downloadPath":"/mnt/SecStorage/19e03beb-309a-3316-8e6d-5f25071372e5/template/tmpl/1/7/dnld5043761750658787860tmp_","installPath":"template/tmpl/1/7","templateSize":0,"templatePhySicalSize":0,"checkSum":"f6f881b7f2292948d8494db837fe0f47","result":true,"details":"
","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&response=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&response=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,"details":"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,"_loadInfo":"{\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.recreateVolume(VolumeOrchestrator.java:1205)

at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1257)

at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:988)

at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5195)

at sun.reflect.GeneratedMethodAccessor465.invoke(Unknown Source) 
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
at java.lang.reflect.Method.invoke(Method.java:606) 
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) 
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5340)

at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) 
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)

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 org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.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":false,"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":false,"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,"vmName":"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: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAG3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAXBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAAFxAH4ACnBwcHEAfgAKcHNyABFqYXZhLnV0aWwuSGFzaE1hcAUH2sHDFmDRAwACRgAKbG9hZEZhY3RvckkACXRocmVzaG9sZHhwP0AAAAAAAAx3CAAAABAAAAABdAAKVm1QYXNzd29yZHQAHHJPMEFCWFFBRG5OaGRtVmtYM0JoYzNOM2IzSmt4cA,
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(VirtualMachineManagerImpl.java:947)

at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5195)

at sun.reflect.GeneratedMethodAccessor465.invoke(Unknown Source) 
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 
at java.lang.reflect.Method.invoke(Method.java:606) 
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) 
at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5340)

at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) 
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)

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 org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.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: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QAUEpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBVbmFibGUgdG8gY3JlYXRlIGEgZGVwbG95bWVudCBmb3IgVk1bVXNlcnxpLTItMjctVk1ddXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAANc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AARMAAhmaWxlTmFtZXEAfgAETAAKbWV0aG9kTmFtZXEAfgAEeHAAAABydAAgY29tLmNsb3VkLnZtLlZtV29ya0pvYkRpc3BhdGNoZXJ0ABhWbVdvcmtKb2JEaXNwYXRjaGVyLmphdmF0AAZydW5Kb2JzcQB-AAsAAAH3dAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0c3EAfgALAAAAMXQAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVuc3EAfgALAAAAOHQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHQkMXQAGkRlZmF1bHRNYW5hZ2VkQ29udGV4dC5qYXZhdAAEY2FsbHNxAH4ACwAAAGd0AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-ABp0AA9jYWxsV2l0aENvbnRleHRzcQB-AAsAAAA1cQB-AB1xAH4AGnQADnJ1bldpdGhDb250ZXh0c3EAfgALAAAALnQAPG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZXEAfgAWcQB-ABdzcQB-AAsAAAHMcQB-ABFxAH4AEnEAfgAXc3EAfgALAAAB13QALmphdmEudXRpbC5jb25jdXJyZW50LkV4ZWN1dG9ycyRSdW5uYWJsZUFkYXB0ZXJ0AA5FeGVjdXRvcnMuamF2YXEAfgAbc3EAfgALAAABBnQAH2phdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2t0AA9GdXR1cmVUYXNrLmphdmFxAH4AF3NxAH4ACwAABHl0ACdqYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3J0ABdUaHJlYWRQb29sRXhlY3V0b3IuamF2YXQACXJ1bldvcmtlcnNxAH4ACwAAAmd0AC5qYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IkV29ya2VycQB-ACxxAH4AF3NxAH4ACwAAAul0ABBqYXZhLmxhbmcuVGhyZWFkdAALVGhyZWFkLmphdmFxAH4AF3NyACZqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlTGlzdPwPJTG17I4QAgABTAAEbGlzdHEAfgAGeHIALGphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVDb2xsZWN0aW9uGUIAgMte9x4CAAFMAAFjdAAWTGphdmEvdXRpbC9Db2xsZWN0aW9uO3hwc3IAE2phdmEudXRpbC5BcnJheUxpc3R4gdIdmcdhnQMAAUkABHNpemV4cAAAAAB3BAAAAAB4cQB-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: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAG3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AApWbVBhc3N3b3JkdAAcck8wQUJYUUFEbk5oZG1Wa1gzQmhjM04zYjNKa3hw,
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":"rO0ABXQADnNhdmVkX3Bhc3N3b3Jk"},"userId":2,"accountId":2,"vmId":27,"handlerName":"VirtualMachineManagerImpl"}

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&response=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.



Wwei@landhightech.com
Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message