Thanks for sharing!
I think, it's not only an SQL-related issue. I raised timeout thresholds of
haproxy, so now there's no DB exceptions since that, but something is
terminating the "cp" process on the SSVM leaving the template incomplete. There
are no messages about the database in the log-file and ACS thinks that the
operation has been finished successfully.
I'm pretty sure that haproxy was a half of a problem, but the second half is
somewhere inside of the SSVM.
On Thu, Feb 01, 2018 at 09:17:51PM +0100, Andrija Panic wrote:
> Vladimir,
>
> the original error seems as MySQL timeout for sure (I assume because of
> HAPROXY in the middle), and we also had this setup originally (MGMT server
> using HAPROXY on top of galera nodes...) but this has confirmed to be
> issue, no matter what we changed on HAproxy or Mysql, and at that time we
> didn't find the solution (MGMT then was set to hit first galera node
> directly...poor man solution) - problem is that it seems when snapshot
> starts (and can take even hours / or conversion to template, same thing...)
> Java keeps the DB connection/transaction open for all time (which is
> strange approach in my head, for such long image-converting actions)
>
> If I'm not wrong, the snapshot to template conversion should be done via
> agent node, not SSVM ?
> Ping here if you find solution.
>
> Btw, for some actions with images the real timeout = 2 x wait parameter :)
> so change that to 2000 and check if actions fails after 4000 sec.
>
>
>
> On 1 February 2018 at 13:00, Vladimir Melnik <v.mel...@uplink.ua> wrote:
>
> > Thanks a lot, any help will be so much appreciated!
> >
> > On Wed, Jan 31, 2018 at 05:23:25PM +0000, Nux! wrote:
> > > It's possible there are timeouts being hit somewhere. I'd take this to
> > dev@ to be honest, I am not very familiar with the ssvm internals.
> > >
> > > --
> > > Sent from the Delta quadrant using Borg technology!
> > >
> > > Nux!
> > > www.nux.ro
> > >
> > > ----- Original Message -----
> > > > From: "Vladimir Melnik" <v.mel...@uplink.ua>
> > > > To: "users" <users@cloudstack.apache.org>
> > > > Sent: Wednesday, 31 January, 2018 12:42:01
> > > > Subject: Re: Time-out when creating a template from a snapshot
> > >
> > > > No, it doesn't seem to be a database-related issue.
> > > >
> > > > This time I haven't got any error messages at all. Moreover, I see
> > this template
> > > > as available in the templates' list and there's the following message
> > in the
> > > > log-file:
> > > > 2018-01-31 14:30:09,862 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> > > > (API-Job-Executor-1:ctx-b39838a2 job-1485421 ctx-3b9d9083)
> > (logid:cb74bce4)
> > > > Complete async job-1485421, jobStatus: SUCCEEDED, resultCode: 0,
> > result:
> > > > org.apache.cloudstack.api.response.TemplateResponse/
> > template/{"id":"b69c65b3-70d6-4000-934c-fac9e887d3ef","name"
> > :"Tucha#2018012713000408","displaytext":"Tucha#
> > 2018012713000408","ispublic":false,"created":"2018-01-
> > 31T13:30:09+0200","isready":true,"passwordenabled":true,"
> > format":"QCOW2","isfeatured":false,"crossZones":false,"
> > ostypeid":"b5490e1c-bd31-11e6-b74f-06973a00088a","ostypename":"Windows
> > > > Server 2012 R2
> > > > (64-bit)","account":"admin#lite","zoneid":"c8d773fa-76ca-
> > 4637-8ecf-88656444fc86","zonename":"z2.tucha13.net","status":"Download
> > > > Complete","size":375809638400,"templatetype":"USER","
> > hypervisor":"KVM","domain":"ROOT","domainid":"b514ef44-
> > bd2f-11e6-b74f-06973a00088a","isextractable":false,"
> > sourcetemplateid":"ba26d2a9-5e2f-468d-8a38-df71a7811ee8","details":{"
> > memoryOvercommitRatio":"1.0","cpuNumber":"4","cpuSpeed":"2399","Message.
> > ReservedCapacityFreed.Flag":"false","cpuOvercommitRatio":"
> > 10","memory":"12288"},"sshkeyenabled":false,"
> > isdynamicallyscalable":false,"tags":[]}
> > > >
> > > > But at the same time I see that the template's file is less than the
> > snapshot's
> > > > file:
> > > > -rw-r--r-- 1 root root 311253204992 Jan 31 00:14
> > > > /mnt/SecStorage/ea7ebf9a-5195-31ab-be8e-f9348f9fee2b/
> > snapshots/4391/12401/e7364ecf-56f2-451d-ba2e-537b9465097f
> > > > -rw-r--r-- 1 root root 195583541248 Jan 31 12:30
> > > > /mnt/SecStorage/ea7ebf9a-5195-31ab-be8e-f9348f9fee2b/
> > template/tmpl/3121/473/e7364ecf-56f2-451d-ba2e-537b9465097f.qcow2
> > > >
> > > > The oddest thing is that the "cp" process in the SSVM is being
> > terminated
> > > > exactly in an hour after its start. Who would be doing that each time
> > I'm
> > > > trying to create a template? Isn't it being done by some script at the
> > SSVM
> > > > itself?
> > > >
> > > >
> > > > On Mon, Jan 29, 2018 at 05:36:54PM +0200, Vladimir Melnik wrote:
> > > >> Thank you, Lucian! My MySQL timeout thresolds are higher than 1 hour,
> > but
> > > >> there's HAproxy between ACS and MySQL, so I've changed haproxy's
> > timeouts and
> > > >> now will see what happens in an hour :-)
> > > >>
> > > >> On Mon, Jan 29, 2018 at 11:47:31AM +0000, Nux! wrote:
> > > >> > I'm usually a sucker with these Java errors, but the error coming
> > from the jdbc
> > > >> > mysql driver makes me think maybe this is related to MySQL timeouts.
> > > >> >
> > > >> > Can you check your db installation for wait_timeouts,
> > interactive_timeout,
> > > >> > connect_timeout and so on, see if any match your 3600 seconds?
> > > >> >
> > > >> > random search result
> > > >> > http://www.supermanhamuerto.com/doku.php?id=java%
> > 3athelastpacketsuccessfullyreceivedfromserver
> > > >> >
> > > >> > hth
> > > >> > Lucian
> > > >> >
> > > >> > --
> > > >> > Sent from the Delta quadrant using Borg technology!
> > > >> >
> > > >> > Nux!
> > > >> > www.nux.ro
> > > >> >
> > > >> > ----- Original Message -----
> > > >> > > From: "Vladimir Melnik" <v.mel...@uplink.ua>
> > > >> > > To: "users" <users@cloudstack.apache.org>
> > > >> > > Sent: Monday, 29 January, 2018 09:29:18
> > > >> > > Subject: Time-out when creating a template from a snapshot
> > > >> >
> > > >> > > 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
> > > >>
> > > >> --
> > > >> V.Melnik
> > > >
> > > > --
> > > > V.Melnik
> >
> > --
> > V.Melnik
> >
>
>
>
> --
>
> Andrija Panić
--
V.Melnik
