cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ugo Vasi <ugo.v...@procne.it.INVALID>
Subject Re: URGENT: Unable to schedule async job for command com.cloud.vm.VmWorkStart, unexpected exception
Date Fri, 14 Dec 2018 09:42:25 GMT
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 <ugo.vasi@procne.it.invalid wrote:
>
>> 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@procne.it <mailto:ugo.vasi@procne.it>
>>
>>
>>
>>
>> *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@procne.it <mailto:info@procne.it>.
>>
>>
>
>
>


-- 

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




*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@procne.it <mailto:info@procne.it>.


Mime
View raw message