I am unable to reliably create templates from volumes. The create
template fails at various percentages complete and will fail multiple
times before the template creates successfully. I am having this problem
with multiple VMs.
The error I receive in CloudStack is Failed to create templateCreating
Template from volume 1a56fd0e-fea3-4423-9cf0-d0a45e4f2391 failed tue to
java.util.concurrent.TimeoutException: NO event for task
OpaqueRef:73321d08-95ae-c099-7591-810f20226a23.
Below is what I see in my logs. Is this some kind of bug?
Thanks,
Alicia
2014-10-17 10:51:39,694 DEBUG [o.a.c.h.x.XenServerResourceNewBase]
(DirectAgent-290:ctx-0b0e908f) Task: ref:OpaqueRef:73321d07-95ae-c099-
7591-810f30336a23, UUID:e5afcfba-89a7-d01f-26b2-3cf6c28c8809 progress:
0.15
2014-10-17 10:51:39,703 WARN [o.a.c.h.x.XenServerResourceNewBase]
(DirectAgent-290:ctx-0b0e908f) No event for task OpaqueRef:73321d07-
95ae-c099-7591-810f30336a23
2014-10-17 10:51:39,738 DEBUG [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-290:ctx-0b0e908f) Host 10.0.0.26 OpaqueRef:4b47b87a-e111-
55b2-be4c-316a0e5ece9e: Removing SR
2014-10-17 10:51:39,745 DEBUG [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-290:ctx-0b0e908f) Host 10.0.0.26 OpaqueRef:4b47b87a-e111-
55b2-be4c-316a0e5ece9e: Catch XenAPIException: This operation cannot be
performed because this VDI is in use by some other operation
2014-10-17 10:51:39,752 DEBUG [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-290:ctx-0b0e908f) Host 10.0.0.26 OpaqueRef:4b47b87a-e111-
55b2-be4c-316a0e5ece9e: Catch XenAPIException: This operation cannot be
performed because this VDI is in use by some other operation
2014-10-17 10:51:39,752 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-290:ctx-0b0e908f) Host 10.0.0.26 OpaqueRef:4b47b87a-e111-
55b2-be4c-316a0e5ece9e: Unable to remove SR
2014-10-17 10:51:40,787 ERROR [c.c.h.x.r.XenServerStorageProcessor]
(DirectAgent-290:ctx-0b0e908f) Creating template from volume 1a56fd0e-
fea3-4423-9cf0-d0a45e4f2391 failed due to
java.util.concurrent.TimeoutException: No event for task
OpaqueRef:73321d07-95ae-c099-7591-810f30336a23
java.util.concurrent.TimeoutException: No event for task
OpaqueRef:73321d07-95ae-c099-7591-810f30336a23
at
org.apache.cloudstack.hypervisor.xenserver.XenServerResourceNewBase.wait
ForTask(XenServerResourceNewBase.java:124)
at
com.cloud.hypervisor.xen.resource.Xenserver625StorageProcessor.createTem
plateFromVolume(Xenserver625StorageProcessor.java:556)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(St
orageSubsystemCommandHandlerBase.java:90)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStor
ageCommands(StorageSubsystemCommandHandlerBase.java:52)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(Citr
ixResourceBase.java:546)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(Xen
Server56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(Xe
nServer610Resource.java:102)
at
com.cloud.hypervisor.xen.resource.XenServer620SP1Resource.executeRequest
(XenServer620SP1Resource.java:65)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgent
Attache.java:216)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Manag
edContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(
DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWit
hContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWith
Context(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Managed
ContextRunnable.java:46)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.acc
ess$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run
(ScheduledThreadPoolExecutor.java:292)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.jav
a:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
va:615)
at java.lang.Thread.run(Thread.java:745)
2014-10-17 10:51:40,792 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-
290:ctx-0b0e908f) Seq 24914-6837871609232003023: Response Received:
2014-10-17 10:51:40,792 DEBUG [c.c.a.t.Request] (DirectAgent-290:ctx-
0b0e908f) Seq 24914-6837871609232003023: Processing: { Ans: , MgmtId:
178252417901011, via: 24914, Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":
{"result":false,"details":"Creating template from volume 1a56fd0e-fea3-
4423-9cf0-d0a45e4f2391 failed due to
java.util.concurrent.TimeoutException: No event for task
OpaqueRef:73321d07-95ae-c099-7591-810f30336a23","wait":0}}] }
2014-10-17 10:51:40,792 DEBUG [c.c.a.t.Request] (API-Job-Executor-
105:ctx-510ed6d2 job-3557 ctx-59b83b75) Seq 24914-6837871609232003023:
Received: { Ans: , MgmtId: 178252417901011, via: 24914, Ver: v1, Flags:
10, { CopyCmdAnswer } }
2014-10-17 10:51:40,797 DEBUG [c.c.t.TemplateManagerImpl] (API-Job-
Executor-105:ctx-510ed6d2 job-3557 ctx-59b83b75) Failed to create
templateCreating template from volume 1a56fd0e-fea3-4423-9cf0-
d0a45e4f2391 failed due to java.util.concurrent.TimeoutException: No
event for task OpaqueRef:73321d07-95ae-c099-7591-810f30336a23
2014-10-17 10:51:40,811 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-
Executor-105:ctx-510ed6d2 job-3557) Unexpected exception while executing
org.apache.cloudstack.api.command.admin.template.CreateTemplateCmdByAdmi
n
com.cloud.utils.exception.CloudRuntimeException: Failed to create
templateCreating template from volume 1a56fd0e-fea3-4423-9cf0-
d0a45e4f2391 failed due to java.util.concurrent.TimeoutException: No
event for task OpaqueRef:73321d07-95ae-c099-7591-810f30336a23
at
com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateMan
agerImpl.java:1402)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.jav
a:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessor
Impl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(
AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinp
oint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Ref
lectiveMethodInvocation.java:150)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterc
eptor.invoke(EventUtils.java:106)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Ref
lectiveMethodInvocation.java:161)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.jav
a:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Ref
lectiveMethodInvocation.java:161)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(E
xposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Ref
lectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAo
pProxy.java:204)
at com.sun.proxy.$Proxy172.createPrivateTemplate(Unknown Source)
at
org.apache.cloudstack.api.command.admin.template.CreateTemplateCmdByAdmi
n.execute(CreateTemplateCmdByAdmin.java:42)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:10
8)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInCon
text(AsyncJobManagerImpl.java:503)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Manag
edContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(
DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWit
hContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWith
Context(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Managed
ContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(Asyn
cJobManagerImpl.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.jav
a:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
va:615)
at java.lang.Thread.run(Thread.java:745)
2014-10-17 10:51:40,813 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-
Job-Executor-105:ctx-510ed6d2 job-3557) Complete async job-3557,
jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":
[],"errorcode":530,"errortext":"Failed to create templateCreating
template from volume 1a56fd0e-fea3-4423-9cf0-d0a45e4f2391 failed due to
java.util.concurrent.TimeoutException: No event for task
OpaqueRef:73321d07-95ae-c099-7591-810f30336a23"}
2014-10-17 10:51:40,823 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-
Job-Executor-105:ctx-510ed6d2 job-3557) Done executing
org.apache.cloudstack.api.command.admin.template.CreateTemplateCmdByAdmi
n for job-3557
2014-10-17 10:51:40,827 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-
Executor-105:ctx-510ed6d2 job-3557) Remove job-3557 from job monitoring
