RE: Unable to schedule async job
Hi Ivan, Did you fixed this issue? If yes, can you please tell me what you did? Thanks in advance. Cristian -Original Message- From: Ivan X Yue Sent: Thursday, January 10, 2019 8:18 PM To: users@cloudstack.apache.org Subject: Re: Unable to schedule async job Dag, That's good idea. How can I update log to debug / trace mode? Thanks Ivan From: Dag Sonstebo To: "users@cloudstack.apache.org" Date: 2019/01/10 11:40 AM Subject: Re: Unable to schedule async job Hi Ivan, Probably a good idea to bump your logging up to debug or trace – these show the SQL queries being prepared in the logs. Regards, Dag Sonstebo Cloud Architect ShapeBlue From: Ivan X Yue Reply-To: "users@cloudstack.apache.org" Date: Thursday, 10 January 2019 at 16:18 To: "users@cloudstack.apache.org" Subject: Re: Unable to schedule async job 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
Unable to schedule async job
Hello, I get following error for any operation on an existing ACS installation. The management server was working well for a few months. This has been started to happen since a few days ago. Unable to schedule async job for command com.cloud.vm.VmWorkStop, unexpected exception. Logs: 2019-07-23 08:39:50,349 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-721f805e job-20128/job-20129 ctx-d234a139) (logid:9403bb3e) Update db status for job-20129 2019-07-23 08:39:50,349 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-721f805e job-20128/job-20129 ctx-d234a139) (logid:9403bb3e) Wake up jobs joined with job-20129 and disjoin all subjobs created from job- 20129 2019-07-23 08:39:50,353 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-1:ctx-721f805e job-20128/job-20129) (logid:9403bb3e) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 264, job origin: 20128 2019-07-23 08:39:50,353 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-721f805e job-20128/job-20129) (logid:9403bb3e) Done executing com.cloud.vm.VmWorkStop for job-20129 2019-07-23 08:39:50,354 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-1:ctx-721f805e job-20128/job-20129) (logid:9403bb3e) Remove job-20129 from job monitoring 2019-07-23 08:39:50,363 DEBUG [c.c.v.VirtualMachineManagerImpl] (API-Job-Executor-6:ctx-3fb9ca20 job-20128 ctx-bd656426) (logid:9403bb3e) Destroying vm VM[User|i-50-264-VM], expunge flag off 2019-07-23 08:39:50,369 DEBUG [c.c.u.d.T.Transaction] (API-Job-Executor-6:ctx-3fb9ca20 job-20128 ctx-bd656426) (logid:9403bb3e) Rolling back the transaction: Time = 0 Name = API-Job-Executor-6; called by -TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-Transaction.execute:43-Transaction.execute:47-AsyncJobManagerImpl.submitAsyncJob:231-VirtualMachineManagerImpl.stopVmThroughJobQueue:4666-VirtualMachineManagerImpl.advanceStop:1599-VirtualMachineManagerImpl.destroy:1864-VMEntityManagerImpl.destroyVirtualMachine:271-VirtualMachineEntityImpl.destroy:233-UserVmManagerImpl.destroyVm:4580 2019-07-23 08:39:50,370 WARN [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-6:ctx-3fb9ca20 job-20128 ctx-bd656426) (logid:9403bb3e) 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:1448) 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:4666) at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1599) at com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1864) 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:4580) at com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:2787) 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
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Hi Andrija, hi all,
this morning I stumbled on the same problem some time ago... after that
catastrophic experience I reinstalled the infrastructure that was
unusable. The current new infrastructure is updated to version 4.11.2.0,
again on Ubuntu 16.04, KVM as hypervisor and Advanced network.
I tried restarting a network and I got an error "Unable to schedule
async job for command com.cloud.vm.VmWorkStart, unexpected exception.".
From what I see in the logs (of which I will report below an excerpt)
The procedure created the new router but at the time of starting it,
something went wrong and the process was canceled.
The exception refers to a "Duplicate entry '1083' for key 'PRIMARY'", so
I analyzed the database dump and I found a record in the "vm_work_job"
table with the primary key id=1083:
INSERT INTO `vm_work_job` VALUES ...
(1081,'Prepare','Instance',45),(1083,'Starting','Instance',45),(1085,'Prepare','Instance',45),(1087,'Starting','Instance',45),(1089,'Starting','Instance',45),(1092,'Starting','Instance',27);
On mysql error log I don't find any error message.
From management-server.log:
2019-02-22 08:26:46,678 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp1096283470-458:ctx-b9d2a3ee ctx-cf002500) (logid:b267e0bd) submit
async job-1082, details: AsyncJobVO {id:1082, userId: 2, accountId: 2,
instanceType: None, instanceId: null, cmd:
org.apache.cloudstack.api.command.user.network.RestartNetworkCmd,
cmdInfo:
{"makeredundant":"false","cleanup":"true","response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"2891","id":"bc0cc3a2-e21f-4904-a826-04477b1805c0","ctxDetails":"{\"interface
com.cloud.network.Network\":\"bc0cc3a2-e21f-4904-a826-04477b1805c0\"}","ctxAccountId":"2","uuid":"bc0cc3a2-e21f-4904-a826-04477b1805c0","cmdEventType":"NETWORK.RESTART","_":"1550820391247"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2019-02-22 08:26:46,721 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-1:ctx-bd6a5e5b job-1082) (logid:ddff8687) Add job-1082
into job monitoring
2019-02-22 08:26:46,727 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-bd6a5e5b job-1082) (logid:f7040f44) Executing
AsyncJobVO {id:1082, userId: 2, accountId: 2, instanceType: None,
instanceId: null, cmd:
org.apache.cloudstack.api.command.user.network.RestartNetworkCmd,
cmdInfo:
{"makeredundant":"false","cleanup":"true","response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"2891","id":"bc0cc3a2-e21f-4904-a826-04477b1805c0","ctxDetails":"{\"interface
com.cloud.network.Network\":\"bc0cc3a2-e21f-4904-a826-04477b1805c0\"}","ctxAccountId":"2","uuid":"bc0cc3a2-e21f-4904-a826-04477b1805c0","cmdEventType":"NETWORK.RESTART","_":"1550820391247"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2019-02-22 08:26:46,793 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(API-Job-Executor-1:ctx-bd6a5e5b job-1082 ctx-d2b2e42b) (logid:f7040f44)
Restarting network 206...
2019-02-22 08:26:46,811 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(API-Job-Executor-1:ctx-bd6a5e5b job-1082 ctx-d2b2e42b) (logid:f7040f44)
Performing rolling restart of routers of network Ntwk[206|Guest|8]
2019-02-22 08:26:46,950 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(API-Job-Executor-1:ctx-bd6a5e5b job-1082 ctx-d2b2e42b) (logid:f7040f44)
Asking VirtualRouter to implemenet Ntwk[206|Guest|8]
2019-02-22 08:26:47,145 DEBUG [c.c.n.r.NetworkHelperImpl]
(API-Job-Executor-1:ctx-bd6a5e5b job-1082 ctx-d2b2e42b) (logid:f7040f44)
Allocating the VR with id=47 in datacenter
com.cloud.dc.DataCenterVO$$EnhancerByCGLIB$$2e90024a@1 with the
hypervisor type KVM
2019-02-22 08:26:47,161 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-12:null) (logid:) SeqA 2-159198: Processing Seq
2-159198: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2019-02-22 08:26:47,163 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-12:null) (logid:) SeqA 2-159198: Sending Seq
2-159198: { Ans: , MgmtId: 220777304233416, via: 2, Ver: v1, F
Re: Unable to schedule async job
/etc/cloudstack/management/log4j-cloud.xml more info: https://image.slidesharecdn.com/cloudstacktroubleshooting-lily-150506063617-conversion-gate02/95/cloud-stack-troubleshooting-12-638.jpg?cb=1430894327 cheers On Thu, 10 Jan 2019 at 19:17, Ivan X Yue wrote: > Dag, > > That's good idea. How can I update log to debug / trace mode? > > Thanks > Ivan > > > > From: Dag Sonstebo > To: "users@cloudstack.apache.org" > Date: 2019/01/10 11:40 AM > Subject:Re: Unable to schedule async job > > > > Hi Ivan, > > Probably a good idea to bump your logging up to debug or trace – these > show the SQL queries being prepared in the logs. > > Regards, > Dag Sonstebo > Cloud Architect > ShapeBlue > > > From: Ivan X Yue > Reply-To: "users@cloudstack.apache.org" > Date: Thursday, 10 January 2019 at 16:18 > To: "users@cloudstack.apache.org" > Subject: Re: Unable to schedule async job > > 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.ap
Re: Unable to schedule async job
Dag, That's good idea. How can I update log to debug / trace mode? Thanks Ivan From: Dag Sonstebo To: "users@cloudstack.apache.org" Date: 2019/01/10 11:40 AM Subject: Re: Unable to schedule async job Hi Ivan, Probably a good idea to bump your logging up to debug or trace – these show the SQL queries being prepared in the logs. Regards, Dag Sonstebo Cloud Architect ShapeBlue From: Ivan X Yue Reply-To: "users@cloudstack.apache.org" Date: Thursday, 10 January 2019 at 16:18 To: "users@cloudstack.apache.org" Subject: Re: Unable to schedule async job 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.sn
Re: Unable to schedule async job
Hi Ivan, Probably a good idea to bump your logging up to debug or trace – these show the SQL queries being prepared in the logs. Regards, Dag Sonstebo Cloud Architect ShapeBlue From: Ivan X Yue Reply-To: "users@cloudstack.apache.org" Date: Thursday, 10 January 2019 at 16:18 To: "users@cloudstack.apache.org" Subject: Re: Unable to schedule async job 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 |
Re: Unable to schedule async job
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: ivan...@ca.ibm.com Email: ivan_...@persistent.com From: Dag Sonstebo To: "users@cloudstack.apache.org" 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" 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
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" 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(Async
Unable to schedule async job
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
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
That's funny - does restarting mgmg helps ? I assume you restored full
cloud DB "property"...
On Fri, Dec 14, 2018, 09:42 Ugo Vasi Hi Andrija,
> I restored database but now I can't see any instance, host or system vm.
> On dashboard I see a real situation statistics but I can't see any data,
> neither via webUI nor via cloudmonkey... I verify existence of the
> instances/hosts data on cloud's database tables.
>
>
>
> Il 13/12/18 17:22, Andrija Panic ha scritto:
> > Done it once (8h old DB)...make sure to kill any new VMs that were
> created
> > in that period of time (and volumes/templates on the end storage).
> >
> > You might run into situation that some VMs are i.e. powered on during
> that
> > last 8h, so DB state for that VM will not be in sync with reality, but
> that
> > should be synced shorty after.
> >
> > I.e. hope that a very few changes/creations of any resources have
> happened
> > during that period - and expect some stuff will need to be manually
> > synced/fixed/repeated - i.e. user created PF rule on VR, but now you have
> > restored DB so - that might be a challenge to fix without pissing off
> users
> > :)
> >
> > Fingers crossed!
> >
> > On Thu, Dec 13, 2018, 14:33 Ugo Vasi >
> >> Hi all,
> >> is there anyone who tried to restore the database a day ago and
> >> restarted cloudstack manager?
> >>
> >> The two situations differ for the status of the VM / VR and I do not
> >> know what to expect and bearing in mind that the problem could recur.
> >>
> >> The statistics don't interest me.
> >>
> >>
> >> Il 13/12/18 10:39, Ugo Vasi ha scritto:
> >>> We have verified that the problem is not tied to a vm but it also
> >>> concerns the other VMs that are stopped. Trying to restart them gives
> >>> the same error message.
> >>>
> >>> Restoring the previous day's database which problems might imply?
> >>>
> >>>
> >>> Il 13/12/18 09:01, Ugo Vasi ha scritto:
> >>>> Hi all,
> >>>> I'm trying to reboot a vm after the host it ran on crashed and
> >>>> restarted from the HA system. All the VMs running on the rebooted
> >>>> host were restarted on other hosts except one.
> >>>> In the web interface and using cloudmonkey I get this message:
> >>>>"Unable to schedule async job for command com.cloud.vm.VmWorkStart,
> >>>> unexpected exception."
> >>>>
> >>>> In the management-server.log file there would seem to be a problem
> >>>> when creating an element that is duplicated (Duplicate entry ''
> >>>> for key 'PRIMARY'):
> >>>>
> >>>> 2018-12-13 08:44:06,659 DEBUG [c.c.a.ApiServlet]
> >>>> (qtp1096283470-445:ctx-6c065e06) (logid:87edf8d7) ===START===
> >>>> 10.80.0.6 -- GET
> >>>>
> >>
> command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
> >>>> 2018-12-13 08:44:06,665 DEBUG [c.c.a.ApiServer]
> >>>> (qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) CIDRs
> >>>> from which account 'Acct[26e597f2-b5ca-11e8-a619-c8cbb8cb15cd-admin]'
> >>>> is allowed to perform API calls: 0.0.0.0/0,::/0
> >>>> 2018-12-13 08:44:06,693 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> >>>> (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:7e0c4dc9) Add
> >>>> job-1343 into job monitoring
> >>>> 2018-12-13 08:44:06,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> >>>> (qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) submit
> >>>> async job-1343, details: AsyncJobVO {id:1343, userId: 2, accountId:
> >>>> 2, instanceType: VirtualMachine, instanceId: 8, cmd:
> >>>> org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin,
> >>>> cmdInfo:
> >>>>
> >>
> {"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
> >>
> >>
> com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
> >>
> >>
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Hi Andrija,
I restored database but now I can't see any instance, host or system vm.
On dashboard I see a real situation statistics but I can't see any data,
neither via webUI nor via cloudmonkey... I verify existence of the
instances/hosts data on cloud's database tables.
Il 13/12/18 17:22, Andrija Panic ha scritto:
Done it once (8h old DB)...make sure to kill any new VMs that were created
in that period of time (and volumes/templates on the end storage).
You might run into situation that some VMs are i.e. powered on during that
last 8h, so DB state for that VM will not be in sync with reality, but that
should be synced shorty after.
I.e. hope that a very few changes/creations of any resources have happened
during that period - and expect some stuff will need to be manually
synced/fixed/repeated - i.e. user created PF rule on VR, but now you have
restored DB so - that might be a challenge to fix without pissing off users
:)
Fingers crossed!
On Thu, Dec 13, 2018, 14:33 Ugo Vasi
Hi all,
is there anyone who tried to restore the database a day ago and
restarted cloudstack manager?
The two situations differ for the status of the VM / VR and I do not
know what to expect and bearing in mind that the problem could recur.
The statistics don't interest me.
Il 13/12/18 10:39, Ugo Vasi ha scritto:
We have verified that the problem is not tied to a vm but it also
concerns the other VMs that are stopped. Trying to restart them gives
the same error message.
Restoring the previous day's database which problems might imply?
Il 13/12/18 09:01, Ugo Vasi ha scritto:
Hi all,
I'm trying to reboot a vm after the host it ran on crashed and
restarted from the HA system. All the VMs running on the rebooted
host were restarted on other hosts except one.
In the web interface and using cloudmonkey I get this message:
"Unable to schedule async job for command com.cloud.vm.VmWorkStart,
unexpected exception."
In the management-server.log file there would seem to be a problem
when creating an element that is duplicated (Duplicate entry ''
for key 'PRIMARY'):
2018-12-13 08:44:06,659 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06) (logid:87edf8d7) ===START===
10.80.0.6 -- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,665 DEBUG [c.c.a.ApiServer]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) CIDRs
from which account 'Acct[26e597f2-b5ca-11e8-a619-c8cbb8cb15cd-admin]'
is allowed to perform API calls: 0.0.0.0/0,::/0
2018-12-13 08:44:06,693 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:7e0c4dc9) Add
job-1343 into job monitoring
2018-12-13 08:44:06,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) submit
async job-1343, details: AsyncJobVO {id:1343, userId: 2, accountId:
2, instanceType: VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin,
cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,700 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Executing
AsyncJobVO {id:1343, userId: 2, accountId: 2, instanceType:
VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin,
cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,705 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7)
===END=== 10.80.0.6 -- GET
command=startVirtualMachine
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Done it once (8h old DB)...make sure to kill any new VMs that were created
in that period of time (and volumes/templates on the end storage).
You might run into situation that some VMs are i.e. powered on during that
last 8h, so DB state for that VM will not be in sync with reality, but that
should be synced shorty after.
I.e. hope that a very few changes/creations of any resources have happened
during that period - and expect some stuff will need to be manually
synced/fixed/repeated - i.e. user created PF rule on VR, but now you have
restored DB so - that might be a challenge to fix without pissing off users
:)
Fingers crossed!
On Thu, Dec 13, 2018, 14:33 Ugo Vasi Hi all,
> is there anyone who tried to restore the database a day ago and
> restarted cloudstack manager?
>
> The two situations differ for the status of the VM / VR and I do not
> know what to expect and bearing in mind that the problem could recur.
>
> The statistics don't interest me.
>
>
> Il 13/12/18 10:39, Ugo Vasi ha scritto:
> > We have verified that the problem is not tied to a vm but it also
> > concerns the other VMs that are stopped. Trying to restart them gives
> > the same error message.
> >
> > Restoring the previous day's database which problems might imply?
> >
> >
> > Il 13/12/18 09:01, Ugo Vasi ha scritto:
> >> Hi all,
> >> I'm trying to reboot a vm after the host it ran on crashed and
> >> restarted from the HA system. All the VMs running on the rebooted
> >> host were restarted on other hosts except one.
> >> In the web interface and using cloudmonkey I get this message:
> >> "Unable to schedule async job for command com.cloud.vm.VmWorkStart,
> >> unexpected exception."
> >>
> >> In the management-server.log file there would seem to be a problem
> >> when creating an element that is duplicated (Duplicate entry ''
> >> for key 'PRIMARY'):
> >>
> >> 2018-12-13 08:44:06,659 DEBUG [c.c.a.ApiServlet]
> >> (qtp1096283470-445:ctx-6c065e06) (logid:87edf8d7) ===START===
> >> 10.80.0.6 -- GET
> >>
> command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
> >> 2018-12-13 08:44:06,665 DEBUG [c.c.a.ApiServer]
> >> (qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) CIDRs
> >> from which account 'Acct[26e597f2-b5ca-11e8-a619-c8cbb8cb15cd-admin]'
> >> is allowed to perform API calls: 0.0.0.0/0,::/0
> >> 2018-12-13 08:44:06,693 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> >> (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:7e0c4dc9) Add
> >> job-1343 into job monitoring
> >> 2018-12-13 08:44:06,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> >> (qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) submit
> >> async job-1343, details: AsyncJobVO {id:1343, userId: 2, accountId:
> >> 2, instanceType: VirtualMachine, instanceId: 8, cmd:
> >> org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin,
> >> cmdInfo:
> >>
> {"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
>
> >>
> com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
>
> >> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> >> result: null, initMsid: 220777304233416, completeMsid: null,
> >> lastUpdated: null, lastPolled: null, created: null}
> >> 2018-12-13 08:44:06,700 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> >> (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Executing
> >> AsyncJobVO {id:1343, userId: 2, accountId: 2, instanceType:
> >> VirtualMachine, instanceId: 8, cmd:
> >> org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin,
> >> cmdInfo:
> >>
> {"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
>
> >>
> com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Hi all,
is there anyone who tried to restore the database a day ago and
restarted cloudstack manager?
The two situations differ for the status of the VM / VR and I do not
know what to expect and bearing in mind that the problem could recur.
The statistics don't interest me.
Il 13/12/18 10:39, Ugo Vasi ha scritto:
We have verified that the problem is not tied to a vm but it also
concerns the other VMs that are stopped. Trying to restart them gives
the same error message.
Restoring the previous day's database which problems might imply?
Il 13/12/18 09:01, Ugo Vasi ha scritto:
Hi all,
I'm trying to reboot a vm after the host it ran on crashed and
restarted from the HA system. All the VMs running on the rebooted
host were restarted on other hosts except one.
In the web interface and using cloudmonkey I get this message:
"Unable to schedule async job for command com.cloud.vm.VmWorkStart,
unexpected exception."
In the management-server.log file there would seem to be a problem
when creating an element that is duplicated (Duplicate entry ''
for key 'PRIMARY'):
2018-12-13 08:44:06,659 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06) (logid:87edf8d7) ===START===
10.80.0.6 -- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,665 DEBUG [c.c.a.ApiServer]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) CIDRs
from which account 'Acct[26e597f2-b5ca-11e8-a619-c8cbb8cb15cd-admin]'
is allowed to perform API calls: 0.0.0.0/0,::/0
2018-12-13 08:44:06,693 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:7e0c4dc9) Add
job-1343 into job monitoring
2018-12-13 08:44:06,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) submit
async job-1343, details: AsyncJobVO {id:1343, userId: 2, accountId:
2, instanceType: VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin,
cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,700 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Executing
AsyncJobVO {id:1343, userId: 2, accountId: 2, instanceType:
VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin,
cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,705 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7)
===END=== 10.80.0.6 -- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,745 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) Service SecurityGroup is not supported in the
network id=205
2018-12-13 08:44:06,752 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) Service SecurityGroup is not supported in the
network id=205
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) DeploymentPlanner allocation algorithm: null
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) Trying to allocate a host and storage pools from
dc:1, pod:null,cluster:null, requested cpu: 8000, requested ram:
8594128896
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Hi On 12/13/18 11:50 AM, Ugo Vasi wrote: > Hi René , > the cloustack installation is 4.11.1.0. From the issue you reported to > me I do not understand if the problem has been solved or not.. > > The big problem is that I can not perform any new jobs. > > In addition to the stopped VM there are two routes that were running on > the host that has crashed. > > One of these routers was redundant as a master of one of the isolated > networks along with another that has taken its place and is now working. As far as I can see, this issue is not solved. It is exactly the same issue we encountered. It seems, that after a while "job timeout? job cleanup time?" you will be able to run jobs again. The guys from shapeblue should know more. Regards René
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Hi René ,
the cloustack installation is 4.11.1.0. From the issue you reported to
me I do not understand if the problem has been solved or not..
The big problem is that I can not perform any new jobs.
In addition to the stopped VM there are two routes that were running on
the host that has crashed.
One of these routers was redundant as a master of one of the isolated
networks along with another that has taken its place and is now working.
Il 13/12/18 11:07, Rene Moser ha scritto:
Hi
I think you hit https://github.com/apache/cloudstack/issues/2880
Is this already 4.11.2?
We have also seen this in our lab, could not really reproduce it, seems
to be a race condition.
Regards
René
On 12/13/18 9:01 AM, Ugo Vasi wrote:
Hi all,
I'm trying to reboot a vm after the host it ran on crashed and restarted
from the HA system. All the VMs running on the rebooted host were
restarted on other hosts except one.
In the web interface and using cloudmonkey I get this message:
"Unable to schedule async job for command com.cloud.vm.VmWorkStart,
unexpected exception."
In the management-server.log file there would seem to be a problem when
creating an element that is duplicated (Duplicate entry '' for key
'PRIMARY'):
2018-12-13 08:44:06,659 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06) (logid:87edf8d7) ===START=== 10.80.0.6
-- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,665 DEBUG [c.c.a.ApiServer]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) CIDRs
from which account 'Acct[26e597f2-b5ca-11e8-a619-c8cbb8cb15cd-admin]' is
allowed to perform API calls: 0.0.0.0/0,::/0
2018-12-13 08:44:06,693 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:7e0c4dc9) Add job-1343
into job monitoring
2018-12-13 08:44:06,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) submit
async job-1343, details: AsyncJobVO {id:1343, userId: 2, accountId: 2,
instanceType: VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,700 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Executing
AsyncJobVO {id:1343, userId: 2, accountId: 2, instanceType:
VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,705 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7)
===END=== 10.80.0.6 -- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,745 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
Service SecurityGroup is not supported in the network id=205
2018-12-13 08:44:06,752 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
Service SecurityGroup is not supported in the network id=205
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
DeploymentPlanner allocation algorithm: null
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
Trying to allocate a host and storage pools from dc:1,
pod:null,cluster:null,
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Hi
I think you hit https://github.com/apache/cloudstack/issues/2880
Is this already 4.11.2?
We have also seen this in our lab, could not really reproduce it, seems
to be a race condition.
Regards
René
On 12/13/18 9:01 AM, Ugo Vasi wrote:
> Hi all,
> I'm trying to reboot a vm after the host it ran on crashed and restarted
> from the HA system. All the VMs running on the rebooted host were
> restarted on other hosts except one.
> In the web interface and using cloudmonkey I get this message:
> "Unable to schedule async job for command com.cloud.vm.VmWorkStart,
> unexpected exception."
>
> In the management-server.log file there would seem to be a problem when
> creating an element that is duplicated (Duplicate entry '' for key
> 'PRIMARY'):
>
> 2018-12-13 08:44:06,659 DEBUG [c.c.a.ApiServlet]
> (qtp1096283470-445:ctx-6c065e06) (logid:87edf8d7) ===START=== 10.80.0.6
> -- GET
> command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
>
> 2018-12-13 08:44:06,665 DEBUG [c.c.a.ApiServer]
> (qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) CIDRs
> from which account 'Acct[26e597f2-b5ca-11e8-a619-c8cbb8cb15cd-admin]' is
> allowed to perform API calls: 0.0.0.0/0,::/0
> 2018-12-13 08:44:06,693 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:7e0c4dc9) Add job-1343
> into job monitoring
> 2018-12-13 08:44:06,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) submit
> async job-1343, details: AsyncJobVO {id:1343, userId: 2, accountId: 2,
> instanceType: VirtualMachine, instanceId: 8, cmd:
> org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin, cmdInfo:
> {"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
> com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 220777304233416, completeMsid: null,
> lastUpdated: null, lastPolled: null, created: null}
> 2018-12-13 08:44:06,700 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Executing
> AsyncJobVO {id:1343, userId: 2, accountId: 2, instanceType:
> VirtualMachine, instanceId: 8, cmd:
> org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin, cmdInfo:
> {"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
> com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
> result: null, initMsid: 220777304233416, completeMsid: null,
> lastUpdated: null, lastPolled: null, created: null}
> 2018-12-13 08:44:06,705 DEBUG [c.c.a.ApiServlet]
> (qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7)
> ===END=== 10.80.0.6 -- GET
> command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
>
> 2018-12-13 08:44:06,745 DEBUG [c.c.n.NetworkModelImpl]
> (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
> Service SecurityGroup is not supported in the network id=205
> 2018-12-13 08:44:06,752 DEBUG [c.c.n.NetworkModelImpl]
> (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
> Service SecurityGroup is not supported in the network id=205
> 2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
> DeploymentPlanner allocation algorithm: null
> 2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
> Trying to allocate a host and storage pools from dc:1,
> pod:null,cluster:null, requested cpu: 8000, requested ram: 8594128896
> 2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
> (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
> Is ROOT
Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
We have verified that the problem is not tied to a vm but it also
concerns the other VMs that are stopped. Trying to restart them gives
the same error message.
Restoring the previous day's database which problems might imply?
Il 13/12/18 09:01, Ugo Vasi ha scritto:
Hi all,
I'm trying to reboot a vm after the host it ran on crashed and
restarted from the HA system. All the VMs running on the rebooted host
were restarted on other hosts except one.
In the web interface and using cloudmonkey I get this message:
"Unable to schedule async job for command com.cloud.vm.VmWorkStart,
unexpected exception."
In the management-server.log file there would seem to be a problem
when creating an element that is duplicated (Duplicate entry ''
for key 'PRIMARY'):
2018-12-13 08:44:06,659 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06) (logid:87edf8d7) ===START===
10.80.0.6 -- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,665 DEBUG [c.c.a.ApiServer]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) CIDRs
from which account 'Acct[26e597f2-b5ca-11e8-a619-c8cbb8cb15cd-admin]'
is allowed to perform API calls: 0.0.0.0/0,::/0
2018-12-13 08:44:06,693 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:7e0c4dc9) Add
job-1343 into job monitoring
2018-12-13 08:44:06,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) submit
async job-1343, details: AsyncJobVO {id:1343, userId: 2, accountId: 2,
instanceType: VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,700 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Executing
AsyncJobVO {id:1343, userId: 2, accountId: 2, instanceType:
VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,705 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7)
===END=== 10.80.0.6 -- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,745 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) Service SecurityGroup is not supported in the network
id=205
2018-12-13 08:44:06,752 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) Service SecurityGroup is not supported in the network
id=205
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) DeploymentPlanner allocation algorithm: null
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) Trying to allocate a host and storage pools from
dc:1, pod:null,cluster:null, requested cpu: 8000, requested ram:
8594128896
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) Is ROOT volume READY (pool already allocated)?: Yes
2018-12-13 08:44:06,783 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5)
(logid:6e9a71c5) Deploy avoids pods: [], clusters: [], hosts: []
2018-12-13
URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Hi all,
I'm trying to reboot a vm after the host it ran on crashed and restarted
from the HA system. All the VMs running on the rebooted host were
restarted on other hosts except one.
In the web interface and using cloudmonkey I get this message:
"Unable to schedule async job for command com.cloud.vm.VmWorkStart,
unexpected exception."
In the management-server.log file there would seem to be a problem when
creating an element that is duplicated (Duplicate entry '' for key
'PRIMARY'):
2018-12-13 08:44:06,659 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06) (logid:87edf8d7) ===START=== 10.80.0.6
-- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,665 DEBUG [c.c.a.ApiServer]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) CIDRs
from which account 'Acct[26e597f2-b5ca-11e8-a619-c8cbb8cb15cd-admin]' is
allowed to perform API calls: 0.0.0.0/0,::/0
2018-12-13 08:44:06,693 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:7e0c4dc9) Add job-1343
into job monitoring
2018-12-13 08:44:06,698 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7) submit
async job-1343, details: AsyncJobVO {id:1343, userId: 2, accountId: 2,
instanceType: VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,700 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Executing
AsyncJobVO {id:1343, userId: 2, accountId: 2, instanceType:
VirtualMachine, instanceId: 8, cmd:
org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"6170","id":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"dde566b2-ef2c-4f86-a82b-c8286f0c24f7\"}","ctxAccountId":"2","uuid":"dde566b2-ef2c-4f86-a82b-c8286f0c24f7","cmdEventType":"VM.START","_":"1544687047015"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 220777304233416, completeMsid: null,
lastUpdated: null, lastPolled: null, created: null}
2018-12-13 08:44:06,705 DEBUG [c.c.a.ApiServlet]
(qtp1096283470-445:ctx-6c065e06 ctx-c8b27e4a) (logid:87edf8d7)
===END=== 10.80.0.6 -- GET
command=startVirtualMachine=json=dde566b2-ef2c-4f86-a82b-c8286f0c24f7&_=1544687047015
2018-12-13 08:44:06,745 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
Service SecurityGroup is not supported in the network id=205
2018-12-13 08:44:06,752 DEBUG [c.c.n.NetworkModelImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
Service SecurityGroup is not supported in the network id=205
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
DeploymentPlanner allocation algorithm: null
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
Trying to allocate a host and storage pools from dc:1,
pod:null,cluster:null, requested cpu: 8000, requested ram: 8594128896
2018-12-13 08:44:06,774 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
Is ROOT volume READY (pool already allocated)?: Yes
2018-12-13 08:44:06,783 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
Deploy avoids pods: [], clusters: [], hosts: []
2018-12-13 08:44:06,784 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5)
This VM has last host_id specified, trying to choose the same host: 10
2018-12-13 08:44:06,794 DEBUG [c.c.c.CapacityManagerImpl]
(API-Job-Ex
