You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Koushik Das (JIRA)" <ji...@apache.org> on 2014/07/21 14:04:39 UTC
[jira] [Commented] (CLOUDSTACK-7133) [Automation] Failed to reboot
Virtual Machine - Runtime Exception - Unable to Start VM
[ https://issues.apache.org/jira/browse/CLOUDSTACK-7133?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14068438#comment-14068438 ]
Koushik Das commented on CLOUDSTACK-7133:
-----------------------------------------
Since this is tagged "Automation", in future please provide the test case that is failing.
Also as per the error message, looks like the template was removed.
2014-07-11 15:10:51,343 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-108:ctx-d1b37d15 job-420 ctx-b9cc76f0) Unable to start VM f1d98737-f934-4811-b7ef-402844e3b451
java.lang.RuntimeException: Job failed due to exception Resource [Host:1] is unreachable: Host 1: Unable to start instance due to can't find ready template: 203 for data center 1
The below log suggests that the template with id 203 was removed at ~14:00 hrs. The template missing error message was thrown at ~15:10 hrs. So that explains the failure.
2014-07-11 14:00:36,563 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-1:ctx-92806a79 ctx-8344d30a ctx-a57d1c58) submit async job-415, details: AsyncJobVO {id:415, userId: 2, accountId: 2, instanceType: Template, instanceId: 203, cmd: org.apache.cloudstack.api.command.user.template.DeleteTemplateCmd, cmdInfo: {"id":"43c136fe-7c3e-4cd4-a1f3-673a966a9ae6","response":"json","ctxDetails":"{\"com.cloud.template.VirtualMachineTemplate\":\"43c136fe-7c3e-4cd4-a1f3-673a966a9ae6\"}","cmdEventType":"TEMPLATE.DELETE","ctxUserId":"2","httpmethod":"GET","uuid":"43c136fe-7c3e-4cd4-a1f3-673a966a9ae6","ctxAccountId":"2","ctxStartEventId":"856","apiKey":"Ra1mlXzCZU0K1l4MKDWdRbQDU67PCQuRnKYv3hyc-Q8hSvCSFjB32UtifLbS6oYpMeKaf0BCuUidMw0LqZeCMA","signature":"Ojg6EhBHc82c1z2is/NS7JfxQTE\u003d"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 161135757057464, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-07-11 14:00:36,564 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-105:ctx-dcc51ace job-415) Add job-415 into job monitoring
2014-07-11 14:00:36,564 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-105:ctx-dcc51ace job-415) Executing AsyncJobVO {id:415, userId: 2, accountId: 2, instanceType: Template, instanceId: 203, cmd: org.apache.cloudstack.api.command.user.template.DeleteTemplateCmd, cmdInfo: {"id":"43c136fe-7c3e-4cd4-a1f3-673a966a9ae6","response":"json","ctxDetails":"{\"com.cloud.template.VirtualMachineTemplate\":\"43c136fe-7c3e-4cd4-a1f3-673a966a9ae6\"}","cmdEventType":"TEMPLATE.DELETE","ctxUserId":"2","httpmethod":"GET","uuid":"43c136fe-7c3e-4cd4-a1f3-673a966a9ae6","ctxAccountId":"2","ctxStartEventId":"856","apiKey":"Ra1mlXzCZU0K1l4MKDWdRbQDU67PCQuRnKYv3hyc-Q8hSvCSFjB32UtifLbS6oYpMeKaf0BCuUidMw0LqZeCMA","signature":"Ojg6EhBHc82c1z2is/NS7JfxQTE\u003d"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 161135757057464, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-07-11 14:00:36,586 INFO [c.c.t.HypervisorTemplateAdapter] (API-Job-Executor-105:ctx-dcc51ace job-415 ctx-61325156) Delete template from image store: nfs://10.220.112.45/vol/xenrtnfs/755570-N4hlyZ
2014-07-11 14:00:36,587 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (API-Job-Executor-105:ctx-dcc51ace job-415 ctx-61325156) template 203 is already in store:1, type:Image
2014-07-11 14:00:36,597 DEBUG [c.c.a.t.Request] (API-Job-Executor-105:ctx-dcc51ace job-415 ctx-61325156) Seq 4-8499981346708390035: Sending { Cmd , MgmtId: 161135757057464, via: 4(s-2-VM), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/47/203/62666bc5-f17d-38c2-a24a-9cdd5cfde195.vhd","origUrl":"http://download.cloud.com/releases/2.0.0/UbuntuServer-10-04-64bit.vhd.bz2","uuid":"43c136fe-7c3e-4cd4-a1f3-673a966a9ae6","id":203,"format":"VHD","accountId":47,"checksum":"63816a11303fbde1ef5005f55234d6d5","hvm":true,"displayText":"Public Template - Xen","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.220.112.45/vol/xenrtnfs/755570-N4hlyZ","_role":"Image"}},"name":"203-47-320ade10-6314-3ba5-8ed9-898799680b8a","hypervisorType":"XenServer"}},"wait":0}}] }
2014-07-11 14:00:36,822 DEBUG [c.c.a.t.Request] (API-Job-Executor-105:ctx-dcc51ace job-415 ctx-61325156) Seq 4-8499981346708390035: Received: { Ans: , MgmtId: 161135757057464, via: 4, Ver: v1, Flags: 10, { Answer } }
2014-07-11 14:00:36,839 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-105:ctx-dcc51ace job-415 ctx-61325156) Access granted to Acct[9f6536a2-08ed-11e4-887d-928d578f5db8-admin] to Domain:1/ by AffinityGroupAccessChecker
2014-07-11 14:00:36,842 INFO [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-105:ctx-dcc51ace job-415 ctx-61325156) Discrepency in the resource count (original count=5368709120 correct count = 0) for type secondary_storage for account ID 47 is fixed during resource count recalculation.
2014-07-11 14:00:36,848 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-105:ctx-dcc51ace job-415 ctx-61325156) Complete async job-415, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SuccessResponse/null/{"success":true}
2014-07-11 14:00:36,852 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-105:ctx-dcc51ace job-415) Done executing org.apache.cloudstack.api.command.user.template.DeleteTemplateCmd for job-415
2014-07-11 14:00:36,855 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-105:ctx-dcc51ace job-415) Remove job-415 from job monitoring
> [Automation] Failed to reboot Virtual Machine - Runtime Exception - Unable to Start VM
> --------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-7133
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7133
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Management Server
> Affects Versions: 4.5.0
> Reporter: Chandan Purushothama
> Assignee: Koushik Das
> Priority: Critical
> Fix For: 4.5.0
>
> Attachments: management-server(1).zip
>
>
> =================================
> Runtime Exception during VM Reboot Job:
> =================================
> 2014-07-11 15:10:51,329 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-119:ctx-2cd21b46 job-420/job-422) Complete async job-422, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QAlkpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBSZXNvdXJjZSBbSG9zdDoxXSBpcyB1bnJlYWNoYWJsZTogSG9zdCAxOiBVbmFibGUgdG8gc3RhcnQgaW5zdGFuY2UgZHVlIHRvIGNhbid0IGZpbmQgcmVhZHkgdGVtcGxhdGU6IDIwMyBmb3IgZGF0YSBjZW50ZXIgMXVyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAADnNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIABEkACmxpbmVOdW1iZXJMAA5kZWNsYXJpbmdDbGFzc3EAfgAETAAIZmlsZU5hbWVxAH4ABEwACm1ldGhvZE5hbWVxAH4ABHhwAAAAcnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9ic3EAfgALAAAB-3QAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHNxAH4ACwAAADF0AD5vcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGUkMXQAG01hbmFnZWRDb250ZXh0UnVubmFibGUuamF2YXQAA3J1bnNxAH4ACwAAADh0AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxzcQB-AAsAAABndABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgAadAAPY2FsbFdpdGhDb250ZXh0c3EAfgALAAAANXEAfgAdcQB-ABp0AA5ydW5XaXRoQ29udGV4dHNxAH4ACwAAAC50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AFnEAfgAXc3EAfgALAAAB0HEAfgARcQB-ABJxAH4AF3NxAH4ACwAAAdd0AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4AG3NxAH4ACwAAAU50ACRqYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrJFN5bmN0AA9GdXR1cmVUYXNrLmphdmF0AAhpbm5lclJ1bnNxAH4ACwAAAKZ0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrcQB-AClxAH4AF3NxAH4ACwAABFZ0ACdqYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3J0ABdUaHJlYWRQb29sRXhlY3V0b3IuamF2YXQACXJ1bldvcmtlcnNxAH4ACwAAAlt0AC5qYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IkV29ya2VycQB-AC9xAH4AF3NxAH4ACwAAAtJ0ABBqYXZhLmxhbmcuVGhyZWFkdAALVGhyZWFkLmphdmFxAH4AF3NyACZqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlTGlzdPwPJTG17I4QAgABTAAEbGlzdHEAfgAGeHIALGphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVDb2xsZWN0aW9uGUIAgMte9x4CAAFMAAFjdAAWTGphdmEvdXRpbC9Db2xsZWN0aW9uO3hwc3IAE2phdmEudXRpbC5BcnJheUxpc3R4gdIdmcdhnQMAAUkABHNpemV4cAAAAAB3BAAAAAB4cQB-ADt4
> 2014-07-11 15:10:51,338 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-119:ctx-2cd21b46 job-420/job-422) Done executing com.cloud.vm.VmWorkStart for job-422
> 2014-07-11 15:10:51,343 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-108:ctx-d1b37d15 job-420 ctx-b9cc76f0) Unable to start VM f1d98737-f934-4811-b7ef-402844e3b451
> java.lang.RuntimeException: Job failed due to exception Resource [Host:1] is unreachable: Host 1: Unable to start instance due to can't find ready template: 203 for data center 1
> at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
> at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:507)
> 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:464)
> 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:722)
> 2014-07-11 15:10:51,353 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-108:ctx-d1b37d15 job-420) Unexpected exception while executing org.apache.cloudstack.api.command.admin.vm.RebootVMCmdByAdmin
> com.cloud.utils.exception.CloudRuntimeException: Unable to start VM with specified idJob failed due to exception Resource [Host:1] is unreachable: Host 1: Unable to start instance due to can't find ready template: 203 for data center 1
> at com.cloud.vm.UserVmManagerImpl.restoreVMInternal(UserVmManagerImpl.java:4738)
> at com.cloud.vm.UserVmManagerImpl.rebootVirtualMachine(UserVmManagerImpl.java:2086)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:601)
> at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:106)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at $Proxy208.rebootVirtualMachine(Unknown Source)
> at org.apache.cloudstack.api.command.admin.vm.RebootVMCmdByAdmin.execute(RebootVMCmdByAdmin.java:41)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
> at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
> at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:507)
> 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:464)
> 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:722)
> 2014-07-11 15:10:51,354 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-108:ctx-d1b37d15 job-420) Complete async job-420, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable to start VM with specified idJob failed due to exception Resource [Host:1] is unreachable: Host 1: Unable to start instance due to can\u0027t find ready template: 203 for data center 1"}
> 2014-07-11 15:10:51,357 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-119:ctx-2cd21b46 job-420/job-422) Sync queue (107) is currently empty
> 2014-07-11 15:10:51,357 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-119:ctx-2cd21b46 job-420/job-422) Remove job-422 from job monitoring
--
This message was sent by Atlassian JIRA
(v6.2#6252)