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.v...@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.v...@procne.it <mailto:ugo.v...@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
i...@procne.it <mailto:i...@procne.it>.
--
*Ugo Vasi* / System Administrator
ugo.v...@procne.it <mailto:ugo.v...@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
i...@procne.it <mailto:i...@procne.it>.
