Hi, Dag,
Thank for the reply.
Below is my async_job table. Today, I try to delete some VM.
Interestingly, I can delete some VM and some are failed withthis error:
Caused by:
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException:
Duplicate entry '387' for key 'PRIMARY'
But in the async_job table, I don't see id=387 there.
I have attached part of the Management Server log wrt the delete VM
action.
One minor correction. I am actually using cloudstack 4.11.1 instead of
4.9.2.
MariaDB [cloud]> select id, job_cmd from async_job order by id;
+-----+-----------------------------------------------------------------+
| id | job_cmd |
+-----+-----------------------------------------------------------------+
| 275 | org.apache.cloudstack.api.command.user.network.DeleteNetworkCmd |
| 276 | NULL |
| 281 | NULL |
| 287 | NULL |
| 288 | NULL |
| 292 | NULL |
| 305 | org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd |
| 307 | org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd |
| 309 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 313 | org.apache.cloudstack.api.command.admin.router.StartRouterCmd |
| 314 | NULL |
| 315 | org.apache.cloudstack.api.command.admin.router.StartRouterCmd |
| 316 | com.cloud.vm.VmWorkStart |
| 317 | org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd |
| 319 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 321 | NULL |
| 322 | com.cloud.vm.VmWorkStop |
| 323 | org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd |
| 327 | com.cloud.vm.VmWorkStart |
| 328 | com.cloud.vm.VmWorkStart |
| 329 | NULL |
| 330 | com.cloud.vm.VmWorkStop |
| 332 | org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd |
| 334 | com.cloud.vm.VmWorkStop |
| 335 | com.cloud.vm.VmWorkStart |
| 336 | com.cloud.vm.VmWorkStart |
| 338 | org.apache.cloudstack.api.command.admin.vpc.CreateVPCCmdByAdmin |
| 340 | com.cloud.vm.VmWorkStop |
| 341 | org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd |
| 342 | com.cloud.vm.VmWorkStop |
| 343 | org.apache.cloudstack.api.command.user.vpc.RestartVPCCmd |
| 344 | com.cloud.vm.VmWorkStart |
| 345 | org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd |
| 346 | com.cloud.vm.VmWorkStop |
| 347 | org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd |
| 348 | com.cloud.vm.VmWorkStop |
| 349 | org.apache.cloudstack.api.command.user.vpc.RestartVPCCmd |
| 350 | com.cloud.vm.VmWorkStart |
| 351 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 352 | com.cloud.vm.VmWorkStop |
| 354 | org.apache.cloudstack.api.command.user.network.DeleteNetworkCmd |
| 355 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 356 | com.cloud.vm.VmWorkStop |
| 357 | com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots |
| 358 | com.cloud.vm.VmWorkStop |
| 359 | org.apache.cloudstack.api.command.user.network.DeleteNetworkCmd |
| 360 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 361 | com.cloud.vm.VmWorkStop |
| 362 | com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots |
| 363 | com.cloud.vm.VmWorkStop |
| 364 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 365 | com.cloud.vm.VmWorkStop |
| 366 | com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots |
| 367 | com.cloud.vm.VmWorkStop |
| 368 | org.apache.cloudstack.api.command.user.network.DeleteNetworkCmd |
| 369 | org.apache.cloudstack.api.command.user.network.DeleteNetworkCmd |
| 370 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 372 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 374 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 376 | org.apache.cloudstack.api.command.user.network.DeleteNetworkCmd |
| 377 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 378 | com.cloud.vm.VmWorkStop |
| 380 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 381 | com.cloud.vm.VmWorkStop |
| 383 | org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin |
| 384 | com.cloud.vm.VmWorkStart |
| 385 | org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin |
| 386 | com.cloud.vm.VmWorkStop |
+-----+-----------------------------------------------------------------+
Thanks
------------------------------------------------------------------------
Ivan Yue
Development Manager - CLM SaaS Operations
Persistent Systems Limited
Email: [email protected]
Email: [email protected]
------------------------------------------------------------------------
From: Dag Sonstebo <[email protected]>
To: "[email protected]" <[email protected]>
Date: 2019/01/10 05:01 AM
Subject: Re: Unable to schedule async job
What does your async_job table say around id>330?
Regards,
Dag Sonstebo
Cloud Architect
ShapeBlue
On 10/01/2019, 05:34, "Ivan X Yue" <[email protected]> wrote:
Hi,
I am using CloudStack 4.9.2 with KVM hypervisors. Today, I find that
the
hypervisor is not responding, and therefore I restart it. After that,
I
find that virtual routers are stopped. When I try to start them, I
keep
getting "Unable to schedule async job" error.
From the management-server.log, I see some exception related to MySQL:
Caused by:
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException:
Duplicate entry '333' for key 'PRIMARY'
Is there any cleanup that I need to do in the database? How can I do
that?
Here is the full stacktrace of the exception that I get:
2019-01-09 12:06:31,417 WARN [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-5:ctx-3248f525 job-332 ctx-d797e8bd)
(logid:d37b7ec3)
Unable to schedule async job for command com.cloud.vm.VmWorkStop,
unexpected exception.
javax.persistence.EntityExistsException: Entity already exists:
at
com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1434)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$1.doInTransaction(AsyncJobManagerImpl.java:235)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$1.doInTransaction(AsyncJobManagerImpl.java:231)
at
com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.java:50)
at com.cloud.utils.db.Transaction.execute(Transaction.java:40)
at com.cloud.utils.db.Transaction.execute(Transaction.java:47)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:231)
at
com.cloud.vm.VirtualMachineManagerImpl.stopVmThroughJobQueue(VirtualMachineManagerImpl.java:4498)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1600)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceExpunge(VirtualMachineManagerImpl.java:513)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceExpunge(VirtualMachineManagerImpl.java:502)
at
com.cloud.vm.VirtualMachineManagerImpl.expunge(VirtualMachineManagerImpl.java:491)
at
com.cloud.network.router.NetworkHelperImpl.destroyRouter(NetworkHelperImpl.java:253)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.destroyRouter(VirtualNetworkApplianceManagerImpl.java:350)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy239.destroyRouter(Unknown Source)
at
org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd.execute(DestroyRouterCmd.java:103)
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:581)
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:529)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by:
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException:
Duplicate entry '333' for key 'PRIMARY'
at
sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
... 55 more
2019-01-09 12:06:31,418 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-5:ctx-3248f525 job-332) (logid:d37b7ec3) Unexpected
exception while executing
org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd
com.cloud.utils.exception.CloudRuntimeException: Unable to schedule
async
job for command com.cloud.vm.VmWorkStop, unexpected exception.
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:247)
at
com.cloud.vm.VirtualMachineManagerImpl.stopVmThroughJobQueue(VirtualMachineManagerImpl.java:4498)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1600)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceExpunge(VirtualMachineManagerImpl.java:513)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceExpunge(VirtualMachineManagerImpl.java:502)
at
com.cloud.vm.VirtualMachineManagerImpl.expunge(VirtualMachineManagerImpl.java:491)
at
com.cloud.network.router.NetworkHelperImpl.destroyRouter(NetworkHelperImpl.java:253)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.destroyRouter(VirtualNetworkApplianceManagerImpl.java:350)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy239.destroyRouter(Unknown Source)
at
org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd.execute(DestroyRouterCmd.java:103)
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:581)
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:529)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-01-09 12:06:31,419 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-5:ctx-3248f525 job-332) (logid:d37b7ec3) Complete
async
job-332, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
to schedule async job for command com.cloud.vm.VmWorkStop, unexpected
exception."}
Thanks for all the helps in advance.
Thanks,
Ivan
[email protected]
www.shapeblue.com
Amadeus House, Floral Street, London WC2E 9DPUK
@shapeblue
2019-01-10 09:28:15,688 DEBUG [c.c.a.ApiServlet] (qtp1644443712-10:ctx-622e215d
ctx-e0a98338) (logid:c7997844) ===END=== 10.1.232.241 -- GET
command=destroyVirtualMachine&response=json&id=2ce6c03d-8e7c-4e0e-af75-c7f1171a76df&expunge=true&_=1547134095567
2019-01-10 09:28:15,689 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Executing
AsyncJobVO {id:385, userId: 2, accountId: 2, instanceType: VirtualMachine,
instanceId: 102, cmd:
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","expunge":"true","httpmethod":"GET","ctxStartEventId":"3236","id":"2ce6c03d-8e7c-4e0e-af75-c7f1171a76df","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"2ce6c03d-8e7c-4e0e-af75-c7f1171a76df\"}","ctxAccountId":"2","uuid":"2ce6c03d-8e7c-4e0e-af75-c7f1171a76df","cmdEventType":"VM.DESTROY","_":"1547134095567"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 7419508112190, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null}
2019-01-10 09:28:15,705 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4)
Checking if there are any ongoing snapshots on the ROOT volumes associated with
VM with ID 102
2019-01-10 09:28:15,706 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4) Found
1 no. of volumes of type ROOT for vm with VM ID 102
2019-01-10 09:28:15,706 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4)
Checking status of snapshots for Volume with Volume Id: 109
2019-01-10 09:28:15,707 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4) The
count of ongoing Snapshots for VM with ID 102 and disk type ROOT is 0
2019-01-10 09:28:15,707 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4) Found
no ongoing snapshots on volume of type ROOT, for the vm with id 102
2019-01-10 09:28:15,712 DEBUG [c.c.v.VirtualMachineManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4)
Destroying vm VM[User|i-2-102-VM], expunge flag on
2019-01-10 09:28:15,720 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4) Sync
job-386 execution on object VmWorkJobQueue.102
2019-01-10 09:28:16,761 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-b978f334) (logid:0dce3e94) Execute sync-queue
item: SyncQueueItemVO {id:28, queueId: 322, contentType: AsyncJob, contentId:
386, lastProcessMsid: 7419508112190, lastprocessNumber: 2, lastProcessTime: Thu
Jan 10 09:28:16 CST 2019, created: Thu Jan 10 09:28:15 CST 2019}
2019-01-10 09:28:16,762 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-b978f334) (logid:0dce3e94) Schedule queued job-386
2019-01-10 09:28:16,767 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386) (logid:40867a3d) Add
job-386 into job monitoring
2019-01-10 09:28:16,772 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386) (logid:69e145a4) Executing
AsyncJobVO {id:386, userId: 2, accountId: 2, instanceType: null, instanceId:
null, cmd: com.cloud.vm.VmWorkStop, cmdInfo:
rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAZnQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 7419508112190, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Thu Jan 10 09:28:15 CST 2019}
2019-01-10 09:28:16,772 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386) (logid:69e145a4) Run VM
work job: com.cloud.vm.VmWorkStop for VM 102, job origin: 385
2019-01-10 09:28:16,773 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386 ctx-60ba955e)
(logid:69e145a4) Execute VM work job:
com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":102,"handlerName":"VirtualMachineManagerImpl"}
2019-01-10 09:28:16,776 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386 ctx-60ba955e)
(logid:69e145a4) VM is already stopped: VM[User|i-2-102-VM]
2019-01-10 09:28:16,776 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386 ctx-60ba955e)
(logid:69e145a4) Done executing VM work job:
com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":102,"handlerName":"VirtualMachineManagerImpl"}
2019-01-10 09:28:16,776 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386 ctx-60ba955e)
(logid:69e145a4) Complete async job-386, jobStatus: SUCCEEDED, resultCode: 0,
result: null
2019-01-10 09:28:16,777 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386 ctx-60ba955e)
(logid:69e145a4) Publish async job-386 complete on message bus
2019-01-10 09:28:16,777 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386 ctx-60ba955e)
(logid:69e145a4) Wake up jobs related to job-386
2019-01-10 09:28:16,777 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386 ctx-60ba955e)
(logid:69e145a4) Update db status for job-386
2019-01-10 09:28:16,778 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386 ctx-60ba955e)
(logid:69e145a4) Wake up jobs joined with job-386 and disjoin all subjobs
created from job- 386
2019-01-10 09:28:16,784 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386) (logid:69e145a4) Done with
run of VM work job: com.cloud.vm.VmWorkStop for VM 102, job origin: 385
2019-01-10 09:28:16,784 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386) (logid:69e145a4) Done
executing com.cloud.vm.VmWorkStop for job-386
2019-01-10 09:28:16,785 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-28:ctx-373c44a3 job-385/job-386) (logid:69e145a4) Remove
job-386 from job monitoring
2019-01-10 09:28:16,797 DEBUG [c.c.u.d.T.Transaction]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4)
Rolling back the transaction: Time = 1 Name = API-Job-Executor-27; called by
-TransactionLegacy.rollback:889-TransactionLegacy.removeUpTo:832-TransactionLegacy.close:656-Transaction.execute:43-Transaction.execute:47-AsyncJobManagerImpl.submitAsyncJob:231-VMSnapshotManagerImpl.deleteAllVMSnapshotsThroughJobQueue:1188-VMSnapshotManagerImpl.deleteAllVMSnapshots:945-NativeMethodAccessorImpl.invoke0:-2-NativeMethodAccessorImpl.invoke:62-DelegatingMethodAccessorImpl.invoke:43-Method.invoke:498
2019-01-10 09:28:16,802 WARN [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385 ctx-5ccbbfe9) (logid:69e145a4) Unable
to schedule async job for command
com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, unexpected exception.
javax.persistence.EntityExistsException: Entity already exists:
at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1434)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$1.doInTransaction(AsyncJobManagerImpl.java:235)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$1.doInTransaction(AsyncJobManagerImpl.java:231)
at com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.java:50)
at com.cloud.utils.db.Transaction.execute(Transaction.java:40)
at com.cloud.utils.db.Transaction.execute(Transaction.java:47)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:231)
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.deleteAllVMSnapshotsThroughJobQueue(VMSnapshotManagerImpl.java:1188)
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.deleteAllVMSnapshots(VMSnapshotManagerImpl.java:945)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy198.deleteAllVMSnapshots(Unknown Source)
at
com.cloud.vm.VirtualMachineManagerImpl.deleteVMSnapshots(VirtualMachineManagerImpl.java:1911)
at
com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1884)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.destroyVirtualMachine(VMEntityManagerImpl.java:271)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.destroy(VirtualMachineEntityImpl.java:233)
at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:4537)
at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:2761)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy164.destroyVm(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin.execute(DestroyVMCmdByAdmin.java:46)
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:581)
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:529)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by:
com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException:
Duplicate entry '387' for key 'PRIMARY'
at sun.reflect.GeneratedConstructorAccessor174.newInstance(Unknown
Source)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
... 70 more
2019-01-10 09:28:16,808 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Unexpected
exception while executing
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin
com.cloud.utils.exception.CloudRuntimeException: Unable to schedule async job
for command com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, unexpected
exception.
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:247)
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.deleteAllVMSnapshotsThroughJobQueue(VMSnapshotManagerImpl.java:1188)
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.deleteAllVMSnapshots(VMSnapshotManagerImpl.java:945)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy198.deleteAllVMSnapshots(Unknown Source)
at
com.cloud.vm.VirtualMachineManagerImpl.deleteVMSnapshots(VirtualMachineManagerImpl.java:1911)
at
com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1884)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.destroyVirtualMachine(VMEntityManagerImpl.java:271)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.destroy(VirtualMachineEntityImpl.java:233)
at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:4537)
at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:2761)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy164.destroyVm(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin.execute(DestroyVMCmdByAdmin.java:46)
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:581)
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:529)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-01-10 09:28:16,809 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Complete async
job-385, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
to schedule async job for command
com.cloud.vm.snapshot.VmWorkDeleteAllVMSnapshots, unexpected exception."}
2019-01-10 09:28:16,810 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Publish async
job-385 complete on message bus
2019-01-10 09:28:16,810 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Wake up jobs
related to job-385
2019-01-10 09:28:16,810 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Update db status
for job-385
2019-01-10 09:28:16,811 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Wake up jobs joined
with job-385 and disjoin all subjobs created from job- 385
2019-01-10 09:28:16,814 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Done executing
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for job-385
2019-01-10 09:28:16,815 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-27:ctx-96becf14 job-385) (logid:69e145a4) Remove job-385 from
job monitoring
