We still need more of the log. We need it from the very beginning of
the job the failed (seems like job-92). Also if possible please upload
it somewhere rather than pasting it to an email to conserve the
formatting. It is easier to read with the original formatting.
Best regards,
Kirk
On 10/03/2013 06:17 AM, motty cruz wrote:
> Thank for your reply, here is what i get on the logs:
>
> 2013-10-03 06:07:22,285 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-8:job-92) Cleaning up resources for the vm VM[User|zee] in
> Starting state
> 2013-10-03 06:07:22,289 DEBUG [agent.transport.Request]
> (Job-Executor-8:job-92) Seq 5-1150027132: Sending { Cmd , MgmtId:
> 73644477032, via: 5, Ver: v1, Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"i-2-18-VM","wait":0}}] }
> 2013-10-03 06:07:22,426 DEBUG [agent.transport.Request]
> (AgentManager-Handler-13:null) Seq 5-1150027132: Processing: { Ans: ,
> MgmtId: 73644477032, via: 5, Ver: v1, Flags: 110,
> [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
> 2013-10-03 06:07:22,426 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-13:null) Seq 5-1150027132: No more commands found
> 2013-10-03 06:07:22,426 DEBUG [agent.transport.Request]
> (Job-Executor-8:job-92) Seq 5-1150027132: Received: { Ans: , MgmtId:
> 73644477032, via: 5, Ver: v1, Flags: 110, { StopAnswer } }
> 2013-10-03 06:07:22,435 DEBUG [db.Transaction.Transaction]
> (Job-Executor-8:job-92) Rolling back the transaction: Time = 4 Name =
>
> -AsyncJobManagerImpl$1.run:401-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334-FutureTask.run:166-ThreadPoolExecutor.runWorker:1146-ThreadPoolExecutor$Worker.run:615-Thread.run:679;
> called by
> -Transaction.rollback:890-Transaction.removeUpTo:833-Transaction.close:657-TransactionContextBuilder.interceptComplete:56-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:131-NetworkManagerImpl.release:1687-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VirtualMachineManagerImpl.cleanup:962-VirtualMachineManagerImpl.advanceStart:850-VirtualMachineManagerImpl.start:471-VMEntityManagerImpl.deployVirtualMachine:212-VirtualMachineEntityImpl.deploy:209
> 2013-10-03 06:07:22,440 DEBUG [db.Transaction.Transaction]
> (Job-Executor-8:job-92) Rolling back the transaction: Time = 4 Name =
>
> -AsyncJobManagerImpl$1.run:401-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334-FutureTask.run:166-ThreadPoolExecutor.runWorker:1146-ThreadPoolExecutor$Worker.run:615-Thread.run:679;
> called by
> -Transaction.rollback:890-Transaction.removeUpTo:833-Transaction.close:657-TransactionContextBuilder.interceptComplete:56-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:131-NetworkManagerImpl.release:1687-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VirtualMachineManagerImpl.cleanup:962-VirtualMachineManagerImpl.advanceStart:850-VirtualMachineManagerImpl.start:471-VMEntityManagerImpl.deployVirtualMachine:212-VirtualMachineEntityImpl.deploy:209
> 2013-10-03 06:07:22,441 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-8:job-92) Successfully released network resources for the vm
> VM[User|zee]
> 2013-10-03 06:07:22,441 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-8:job-92) Successfully cleanued up resources for the vm
> VM[User|zee] in Starting state
> 2013-10-03 06:07:22,443 DEBUG [cloud.deploy.FirstFitPlanner]
> (Job-Executor-8:job-92) DataCenter id = '3' provided is in avoid set,
> DeploymentPlanner cannot allocate the VM, returning.
> 2013-10-03 06:07:22,460 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-8:job-92) VM state transitted from :Starting to Stopped with
> event: OperationFailedvm's original host id: null new host id: null host id
> before state transition: 5
> 2013-10-03 06:07:22,468 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-8:job-92) Hosts's actual total CPU: 48000 and CPU after
> applying overprovisioning: 48000
> 2013-10-03 06:07:22,468 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-8:job-92) release cpu from host: 5, old used: 4,reserved: 0,
> actual total: 48000, total with overprovisioning: 48000; new used:
> 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-10-03 06:07:22,468 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-8:job-92) release mem from host: 5, old used:
> 2147483648,reserved: 0, total: 67521658880; new used: 0,reserved:0;
> movedfromreserved: false,moveToReserveredfalse
> 2013-10-03 06:07:22,477 DEBUG [cloud.vm.UserVmManagerImpl]
> (Job-Executor-8:job-92) Destroying vm VM[User|zee] as it failed to create
> on Host with Id:null
> 2013-10-03 06:07:22,493 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-8:job-92) VM state transitted from :Stopped to Error with
> event: OperationFailedToErrorvm's original host id: null new host id: null
> host id before state transition: null
> 2013-10-03 06:07:22,609 INFO [user.vm.DeployVMCmd] (Job-Executor-8:job-92)
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|zee]Scope=interface com.cloud.dc.DataCenter; id=3
>
>
>
> On Wed, Oct 2, 2013 at 8:34 PM, Kirk Kosinski <kirkkosin...@gmail.com>wrote:
>
>> Hi, the log shows a VM being destroyed, which doesn't match the
>> description of the problem. If the description is correct, upload more
>> of the load to Pastebin. The log that needs to be provided will most
>> likely include the error text from the UI.
>>
>> Best regards,
>> Kirk
>>
>> On 10/02/2013 09:59 AM, motty cruz wrote:
>>> Hello,
>>> I'm trying to build a VM but I get the following error "Unable to create
>> a
>>> deployment for VM[User]test4]"
>>>
>>> primary storage is up CLVM,
>>> secondary storage nfs is up
>>>
>>> logs:
>>> 2013-10-02 09:46:07,885 DEBUG [cloud.async.AsyncJobManagerImpl]
>>> (catalina-exec-1:null) submit async job-50, details: AsyncJobVO {id:50,
>>> userId: 2, accountId: 2, sessionKey: null, instanceT
>>> ype: VirtualMachine, instanceId: 8, cmd:
>>> org.apache.cloudstack.api.command.user.vm.DestroyVMCmd, cmdOriginator:
>>> null, cmdInfo:
>> {"id":"9a48d353-f57a-46b4-8a32-3f09fa114409","response":"json
>>>
>> ","sessionkey":"XXXUS8OPHkdR1qhkb8bAUYFHfps\u003d","ctxUserId":"2","_":"1380732367999","ctxAccountId":"2","ctxStartEventId":"204"},
>>> cmdVersion: 0, callbackType: 0, callbackAddress: null, s
>>> tatus: 0, processStatus: 0, resultCode: 0, result: null, initMsid:
>>> 73644477032, completeMsid: null, lastUpdated: null, lastPolled: null,
>>> created: null}
>>> 2013-10-02 09:46:07,887 DEBUG [cloud.async.AsyncJobManagerImpl]
>>> (Job-Executor-3:job-50) Executing
>>> org.apache.cloudstack.api.command.user.vm.DestroyVMCmd for job-50
>>> 2013-10-02 09:46:07,892 DEBUG [cloud.api.ApiServlet]
>> (catalina-exec-1:null)
>>> ===END=== xxxx.xxxx.xxxx.xxxx -- GET
>>>
>>
>> command=destroyVirtualMachine&id=9a48d353-f57a-46b4-8a32-3f09fa114409&response=j
>>> son&sessionkey=XXXUS8OPHkdR1qhkb8bAUYFHfps%3D&_=1380732367999
>>> 2013-10-02 09:46:07,946 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>>> (Job-Executor-3:job-50) Destroying vm VM[User|test4]
>>> 2013-10-02 09:46:07,947 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>>> (Job-Executor-3:job-50) Stopped called on VM[User|test4] but the state is
>>> Error
>>> 2013-10-02 09:46:07,963 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (Job-Executor-3:job-50) VM state transitted from :Error to Expunging with
>>> event: DestroyRequestedvm's original host id: n
>>> ull new host id: null host id before state transition: null
>>> 2013-10-02 09:46:08,001 DEBUG [cloud.async.AsyncJobManagerImpl]
>>> (Job-Executor-3:job-50) Complete async job-50, jobStatus: 1, resultCode:
>> 0,
>>> result: org.apache.cloudstack.api.response.UserV
>>> mResponse@2d453a4b
>>> 2013-10-02 09:46:08,017 DEBUG [cloud.async.AsyncJobManagerImpl]
>>> (Job-Executor-3:job-50) Done executing
>>> org.apache.cloudstack.api.command.user.vm.DestroyVMCmd for job-50
>>> 2013-10-02 09:46:10,931 DEBUG [cloud.api.ApiServlet]
>> (catalina-exec-5:null)
>>> ===START=== xxxx.xxxx.xxxx.xxxx-- GET
>>>
>>
>> command=queryAsyncJobResult&jobId=16b35e61-cedd-4173-90ce-aad61486b001&respons
>>> e=json&sessionkey=XXXUS8OPHkdR1qhkb8bAUYFHfps%3D&_=1380732371066
>>> 2013-10-02 09:46:10,974 DEBUG [cloud.async.AsyncJobManagerImpl]
>>> (catalina-exec-5:null) Async job-50 completed
>>> 2013-10-02 09:46:11,003 DEBUG [cloud.api.ApiServlet]
>> (catalina-exec-5:null)
>>> ===END=== xxxx.xxxx.xxxx.xxxx -- GET
>>> command=queryAsyncJobResult&jobId=16b35e61-cedd-4173-90ce-aad6148
>>>
>>
>
