50LkZ1dHVyZVRhc2t0AA9GdXR1cmVUYXNrLmphdmFxAH4AF3NxAH4ACwAABHl0ACdqYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3J0ABdUaHJlYWRQb29sRXhlY3V0b3IuamF2YXQACXJ1bldvcmtlcnNxAH4ACwAAAmd0AC5qYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IkV29ya2VycQB-ACxxAH4AF3NxAH4ACwAAAul0ABBqYXZhLmxhbmcuVGhyZWFkdAALVGhyZWFkLmphdmFxAH4AF3NyACZqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlTGlzdPwPJTG17I4QAgABTAAEbGlzdHEAfgAGeHIALGphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVDb2xsZWN0aW9uGUIAgMte9x4CAAFMAAFjdAAWTGphdmEvdXRpbC9Db2xsZWN0aW9uO3hwc3IAE2phdmEudXRpbC5BcnJheUxpc3R4gdIdmcdhnQMAAUkABHNpemV4cAB3BAB4cQB-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-AAN4cAACAAIAG3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAADHcIEAF0AApWbVBhc3N3b3JkdAAcck8wQUJYUUFEbk5oZG1Wa1gzQmhjM04zYjNKa3hw,
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.
w...@landhightech.com