git.net

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

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 'xxxx' 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&response=json&id=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&response=json&id=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-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Host: 10 has cpu capability (cpu:12, speed:3000) to support requested CPU: 4 and requested speed: 2000 2018-12-13 08:44:06,794 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking if host: 10 has enough capacity for requested CPU: 8000 and requested RAM: 8594128896 , cpuOverprovisioningFactor: 1.0 2018-12-13 08:44:06,797 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Hosts's actual total CPU: 36000 and CPU after applying overprovisioning: 36000 2018-12-13 08:44:06,797 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) We need to allocate to the last host again, so checking if there is enough reserved capacity 2018-12-13 08:44:06,797 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Reserved CPU: 8000 , Requested CPU: 8000 2018-12-13 08:44:06,797 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Reserved RAM: 8594128896 , Requested RAM: 8594128896 2018-12-13 08:44:06,797 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Host has enough CPU and RAM available 2018-12-13 08:44:06,797 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) STATS: Can alloc CPU from host: 10, used: 4500, reserved: 8000, actual total: 36000, total with overprovisioning: 36000; requested cpu:8000,alloc_from_last_host?:true ,considerReservedCapacity?: true 2018-12-13 08:44:06,797 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) STATS: Can alloc MEM from host: 10, used: 2415919104, reserved: 8594128896, total: 49554284544; requested mem: 8594128896,alloc_from_last_host?:true ,considerReservedCapacity?: true 2018-12-13 08:44:06,797 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) The last host of this VM is UP and has enough capacity 2018-12-13 08:44:06,797 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Now checking for suitable pools under zone: 1, pod: 1, cluster: 1 2018-12-13 08:44:06,803 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking suitable pools for volume (Id, Type): (8,ROOT) 2018-12-13 08:44:06,803 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Volume has pool already allocated, checking if pool can be reused, poolId: 1 2018-12-13 08:44:06,808 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Planner need not allocate a pool for this volume since its READY 2018-12-13 08:44:06,808 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking suitable pools for volume (Id, Type): (12,DATADISK) 2018-12-13 08:44:06,808 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Volume has pool already allocated, checking if pool can be reused, poolId: 1 2018-12-13 08:44:06,814 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Planner need not allocate a pool for this volume since its READY 2018-12-13 08:44:06,814 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking suitable pools for volume (Id, Type): (17,DATADISK) 2018-12-13 08:44:06,814 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Volume has pool already allocated, checking if pool can be reused, poolId: 1 2018-12-13 08:44:06,819 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Planner need not allocate a pool for this volume since its READY 2018-12-13 08:44:06,820 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking suitable pools for volume (Id, Type): (58,DATADISK) 2018-12-13 08:44:06,820 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Volume has pool already allocated, checking if pool can be reused, poolId: 1 2018-12-13 08:44:06,825 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Planner need not allocate a pool for this volume since its READY 2018-12-13 08:44:06,825 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM 2018-12-13 08:44:06,825 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking if host: 10 can access any suitable storage pool for volume: DATADISK 2018-12-13 08:44:06,827 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Host: 10 can access pool: 1 2018-12-13 08:44:06,827 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking if host: 10 can access any suitable storage pool for volume: DATADISK 2018-12-13 08:44:06,829 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Host: 10 can access pool: 1 2018-12-13 08:44:06,829 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking if host: 10 can access any suitable storage pool for volume: DATADISK 2018-12-13 08:44:06,830 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Host: 10 can access pool: 1 2018-12-13 08:44:06,830 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Checking if host: 10 can access any suitable storage pool for volume: ROOT 2018-12-13 08:44:06,831 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Host: 10 can access pool: 1 2018-12-13 08:44:06,833 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Found a potential host id: 10 name: cshp143 and associated storage pools for this VM 2018-12-13 08:44:06,833 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(10)-Storage()] 2018-12-13 08:44:06,856 DEBUG [c.c.u.d.T.Transaction] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Rolling back the transaction: Time = 3 Name = API-Job-Executor-8; called by -TransactionLegacy.rollback:889-TransactionLegacy.removeUpTo:832-TransactionLegacy.close:656-Transaction.execute:43-Transaction.execute:47-AsyncJobManagerImpl.submitAsyncJob:231-VirtualMachineManagerImpl.startVmThroughJobQueue:4457-VirtualMachineManagerImpl.advanceStart:899-VirtualMachineManagerImpl.start:718-VMEntityManagerImpl.deployVirtualMachine:233-VirtualMachineEntityImpl.deploy:212-UserVmManagerImpl.startVirtualMachine:4495 2018-12-13 08:44:06,861 WARN  [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Unable to schedule async job for command com.cloud.vm.VmWorkStart, 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.startVmThroughJobQueue(VirtualMachineManagerImpl.java:4457)         at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:899)         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:718)         at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:233)         at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:212)         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4495)         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2689)
        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.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin.execute(StartVMCmdByAdmin.java:51)
        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 '1344' for key 'PRIMARY'         at sun.reflect.GeneratedConstructorAccessor130.newInstance(Unknown Source)         at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)         at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        ... 59 more
2018-12-13 08:44:06,876 DEBUG [c.c.u.d.T.Transaction] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Rolling back the transaction: Time = 2 Name = API-Job-Executor-8; called by -TransactionLegacy.rollback:889-TransactionLegacy.removeUpTo:832-TransactionLegacy.close:656-Transaction.execute:43-Transaction.execute:47-AsyncJobManagerImpl.submitAsyncJob:231-VirtualMachineManagerImpl.startVmThroughJobQueue:4457-VirtualMachineManagerImpl.advanceStart:899-VirtualMachineManagerImpl.start:718-VMEntityManagerImpl.deployVirtualMachine:245-VirtualMachineEntityImpl.deploy:212-UserVmManagerImpl.startVirtualMachine:4495 2018-12-13 08:44:06,880 WARN  [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343 ctx-eb44a3e5) (logid:6e9a71c5) Unable to schedule async job for command com.cloud.vm.VmWorkStart, 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.startVmThroughJobQueue(VirtualMachineManagerImpl.java:4457)         at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:899)         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:718)         at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:245)         at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:212)         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4495)         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2689)
        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.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin.execute(StartVMCmdByAdmin.java:51)
        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 '1345' for key 'PRIMARY'         at sun.reflect.GeneratedConstructorAccessor130.newInstance(Unknown Source)         at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)         at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        ... 59 more
2018-12-13 08:44:06,889 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Unexpected exception while executing org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin com.cloud.utils.exception.CloudRuntimeException: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception.         at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:247)         at com.cloud.vm.VirtualMachineManagerImpl.startVmThroughJobQueue(VirtualMachineManagerImpl.java:4457)         at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:899)         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:718)         at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:245)         at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:212)         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:4495)         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2689)
        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.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin.execute(StartVMCmdByAdmin.java:51)
        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)
2018-12-13 08:44:06,891 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Complete async job-1343, 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.VmWorkStart, unexpected exception."} 2018-12-13 08:44:06,893 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Publish async job-1343 complete on message bus 2018-12-13 08:44:06,893 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Wake up jobs related to job-1343 2018-12-13 08:44:06,893 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Update db status for job-1343 2018-12-13 08:44:06,895 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Wake up jobs joined with job-1343 and disjoin all subjobs created from job- 1343 2018-12-13 08:44:06,899 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Done executing org.apache.cloudstack.api.command.admin.vm.StartVMCmdByAdmin for job-1343 2018-12-13 08:44:06,899 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-8:ctx-b5905c86 job-1343) (logid:6e9a71c5) Remove job-1343 from job monitoring 2018-12-13 08:44:07,056 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-31fc417b) (logid:36cfc76d) Begin cleanup expired async-jobs 2018-12-13 08:44:07,062 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-31fc417b) (logid:36cfc76d) End cleanup expired async-jobs

This problem has already appeared to me other times (in other circumstances) and I have reported it but I have not found a solution.

Can you help me identify the problem?





--

*Ugo Vasi* / System Administrator
ugo.vasi@xxxxxxxxx <mailto:ugo.vasi@xxxxxxxxx>




*Procne S.r.l.*
+39 0432 486 523
via Cotonificio, 45
33010 Tavagnacco (UD)
www.procne.it <http://www.procne.it/>


Le informazioni contenute nella presente comunicazione ed i relativi allegati possono essere riservate e sono, comunque, destinate esclusivamente alle persone od alla Società sopraindicati. La diffusione, distribuzione e/o copiatura del documento trasmesso da parte di qualsiasi soggetto diverso dal destinatario è proibita sia ai sensi dell'art. 616 c.p., che ai sensi del Decreto Legislativo n. 196/2003 "Codice in materia di protezione dei dati personali". Se avete ricevuto questo messaggio per errore, vi preghiamo di distruggerlo e di informare immediatamente Procne S.r.l. scrivendo all' indirizzo e-mail info@xxxxxxxxx <mailto:info@xxxxxxxxx>.