Dear colleagues,
Would anyone be so kind as to help me to find out how to change time limits for
template creation?
When I create a template from a snapshot, I have only an hour to have it done,
othewise the operation is being terminated exaxtly after 3600 seconds, but I
can't understand why does it happen, as my settings seem to be quite "loose":
create.private.template.from.snapshot.wait = 10800
secstorage.cmd.execution.time.max = 240
vm.job.timeout = 600000
wait = 1800
Here are the messages I see in the management log-file:
2018-01-29 10:22:04,029 WARN [o.a.c.f.j.i.AsyncJobMonitor]
(Timer-1:ctx-7a53941f) (logid:e215433a) Task (job-1476131) has been pending for
3577 seconds
2018-01-29 10:22:26,836 DEBUG [c.c.a.t.Request]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131 ctx-51926357) (logid:a5fbfcf6) Seq
21-5880575213439025165: Received: { Ans: , MgmtId: 7477638727846, via:
21(s-1-VM), Ver: v1, Flags: 110, { CopyCmdAnswer } }
2018-01-29 10:22:26,838 DEBUG [o.a.c.s.i.s.TemplateObject]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131 ctx-51926357) (logid:a5fbfcf6)
failed to process event and answer
com.cloud.utils.exception.CloudRuntimeException: DB Exception on:
com.mysql.jdbc.JDBC4PreparedStatement@1e42ea31: SELECT template_store_ref.id,
template_store_ref.store_id, template_store_ref.template_id,
template_store_ref.store_role, template_store_ref.created,
template_store_ref.last_updated, template_store_ref.download_pct,
template_store_ref.size, template_store_ref.physical_size,
template_store_ref.download_state, template_store_ref.local_path,
template_store_ref.error_str, template_store_ref.job_id,
template_store_ref.install_path, template_store_ref.url,
template_store_ref.download_url, template_store_ref.download_url_created,
template_store_ref.is_copy, template_store_ref.destroyed,
template_store_ref.update_count, template_store_ref.updated,
template_store_ref.state, template_store_ref.ref_cnt FROM template_store_ref
WHERE template_store_ref.store_id = 1 AND template_store_ref.template_id = 471
AND template_store_ref.destroyed = 0 ORDER BY RAND() LIMIT 1
at
com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:427)
at
com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:363)
at
com.cloud.utils.db.GenericDaoBase.findOneIncludingRemovedBy(GenericDaoBase.java:891)
at
org.apache.cloudstack.storage.image.db.TemplateDataStoreDaoImpl.findByStoreTemplate(TemplateDataStoreDaoImpl.java:356)
at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.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.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:34)
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 com.sun.proxy.$Proxy102.findByStoreTemplate(Unknown Source)
at
org.apache.cloudstack.storage.image.store.TemplateObject.processEvent(TemplateObject.java:209)
at
org.apache.cloudstack.storage.image.TemplateServiceImpl.copyTemplateCallBack(TemplateServiceImpl.java:951)
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:606)
at
org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:148)
at
org.apache.cloudstack.framework.async.InplaceAsyncCallbackDriver.performCompletionCallback(InplaceAsyncCallbackDriver.java:25)
at
org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.complete(AsyncCallbackDispatcher.java:126)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:457)
at
org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:68)
at
org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:73)
at
org.apache.cloudstack.storage.image.TemplateServiceImpl.copyAsync(TemplateServiceImpl.java:732)
at
org.apache.cloudstack.storage.image.TemplateServiceImpl.createTemplateFromSnapshotAsync(TemplateServiceImpl.java:738)
at
com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1503)
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:606)
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 com.sun.proxy.$Proxy183.createPrivateTemplate(Unknown Source)
at
org.apache.cloudstack.api.command.admin.template.CreateTemplateCmdByAdmin.execute(CreateTemplateCmdByAdmin.java:43)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
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)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException:
Communications link failure
The last packet successfully received from the server was 3,600,444
milliseconds ago. The last packet sent successfully to the server was 1
milliseconds ago.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
... 74 more
Caused by: java.io.EOFException: Can not read response from server. Expected to
read 4 bytes, read 0 bytes before connection was unexpectedly lost.
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2540)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2990)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2979)
... 69 more
2018-01-29 10:22:26,876 DEBUG [o.a.c.s.i.TemplateServiceImpl]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131 ctx-51926357) (logid:a5fbfcf6)
Failed to process copy template callback
com.cloud.utils.exception.CloudRuntimeException: Failed to process event
at
org.apache.cloudstack.storage.image.store.TemplateObject.processEvent(TemplateObject.java:242)
at
org.apache.cloudstack.storage.image.TemplateServiceImpl.copyTemplateCallBack(TemplateServiceImpl.java:951)
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:606)
at
org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:148)
at
org.apache.cloudstack.framework.async.InplaceAsyncCallbackDriver.performCompletionCallback(InplaceAsyncCallbackDriver.java:25)
at
org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.complete(AsyncCallbackDispatcher.java:126)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:457)
at
org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:68)
at
org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:73)
at
org.apache.cloudstack.storage.image.TemplateServiceImpl.copyAsync(TemplateServiceImpl.java:732)
at
org.apache.cloudstack.storage.image.TemplateServiceImpl.createTemplateFromSnapshotAsync(TemplateServiceImpl.java:738)
at
com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1503)
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:606)
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 com.sun.proxy.$Proxy183.createPrivateTemplate(Unknown Source)
at
org.apache.cloudstack.api.command.admin.template.CreateTemplateCmdByAdmin.execute(CreateTemplateCmdByAdmin.java:43)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
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)
Caused by: com.cloud.utils.exception.CloudRuntimeException: DB Exception on:
com.mysql.jdbc.JDBC4PreparedStatement@1e42ea31: SELECT template_store_ref.id,
template_store_ref.store_id, template_store_ref.template_id,
template_store_ref.store_role, template_store_ref.created,
template_store_ref.last_updated, template_store_ref.download_pct,
template_store_ref.size, template_store_ref.physical_size,
template_store_ref.download_state, template_store_ref.local_path,
template_store_ref.error_str, template_store_ref.job_id,
template_store_ref.install_path, template_store_ref.url,
template_store_ref.download_url, template_store_ref.download_url_created,
template_store_ref.is_copy, template_store_ref.destroyed,
template_store_ref.update_count, template_store_ref.updated,
template_store_ref.state, template_store_ref.ref_cnt FROM template_store_ref
WHERE template_store_ref.store_id = 1 AND template_store_ref.template_id = 471
AND template_store_ref.destroyed = 0 ORDER BY RAND() LIMIT 1
at
com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:427)
at
com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:363)
at
com.cloud.utils.db.GenericDaoBase.findOneIncludingRemovedBy(GenericDaoBase.java:891)
... 58 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException:
Communications link failure
The last packet successfully received from the server was 3,600,444
milliseconds ago. The last packet sent successfully to the server was 1
milliseconds ago.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
... 74 more
Caused by: java.io.EOFException: Can not read response from server. Expected to
read 4 bytes, read 0 bytes before connection was unexpectedly lost.
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2540)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2990)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2979)
... 69 more
2018-01-29 10:22:26,877 DEBUG [c.c.t.TemplateManagerImpl]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131 ctx-51926357) (logid:a5fbfcf6)
Failed to create templatecom.cloud.utils.exception.CloudRuntimeException:
Failed to process event
2018-01-29 10:22:26,936 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131) (logid:a5fbfcf6) Unexpected
exception while executing
org.apache.cloudstack.api.command.admin.template.CreateTemplateCmdByAdmin
com.cloud.utils.exception.CloudRuntimeException: Failed to create
templatecom.cloud.utils.exception.CloudRuntimeException: Failed to process event
at
com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1520)
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:606)
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 com.sun.proxy.$Proxy183.createPrivateTemplate(Unknown Source)
at
org.apache.cloudstack.api.command.admin.template.CreateTemplateCmdByAdmin.execute(CreateTemplateCmdByAdmin.java:43)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
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)
2018-01-29 10:22:26,938 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131) (logid:a5fbfcf6) Complete async
job-1476131, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed
to create templatecom.cloud.utils.exception.CloudRuntimeException: Failed to
process event"}
2018-01-29 10:22:26,943 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131) (logid:a5fbfcf6) Publish async
job-1476131 complete on message bus
2018-01-29 10:22:26,943 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131) (logid:a5fbfcf6) Wake up jobs
related to job-1476131
2018-01-29 10:22:26,943 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131) (logid:a5fbfcf6) Update db status
for job-1476131
2018-01-29 10:22:26,948 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131) (logid:a5fbfcf6) Wake up jobs
joined with job-1476131 and disjoin all subjobs created from job- 1476131
2018-01-29 10:22:26,958 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131) (logid:a5fbfcf6) Done executing
org.apache.cloudstack.api.command.admin.template.CreateTemplateCmdByAdmin for
job-1476131
2018-01-29 10:22:26,958 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-1:ctx-1727ccb3 job-1476131) (logid:a5fbfcf6) Remove
job-1476131 from job monitoring
Would you be so kind as to provide any glues or suggestions? Lot of thanks!
--
V.Melnik
