You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Fariborz Navidan <md...@gmail.com> on 2019/07/23 06:48:47 UTC
Unable to schedule async job
Hello,
I get following error for any operation on an existing ACS installation.
The management server was working well for a few months. This has been
started to happen since a few days ago.
Unable to schedule async job for command com.cloud.vm.VmWorkStop,
unexpected exception.
Logs:
2019-07-23 08:39:50,349 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-1:ctx-721f805e job-20128/job-20129 ctx-d234a139)
(logid:9403bb3e) Update db status for job-20129
2019-07-23 08:39:50,349 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-1:ctx-721f805e job-20128/job-20129 ctx-d234a139)
(logid:9403bb3e) Wake up jobs joined with job-20129 and disjoin all subjobs
created from job- 20129
2019-07-23 08:39:50,353 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-1:ctx-721f805e job-20128/job-20129) (logid:9403bb3e)
Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 264, job
origin: 20128
2019-07-23 08:39:50,353 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-1:ctx-721f805e job-20128/job-20129) (logid:9403bb3e)
Done executing com.cloud.vm.VmWorkStop for job-20129
2019-07-23 08:39:50,354 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-1:ctx-721f805e job-20128/job-20129) (logid:9403bb3e)
Remove job-20129 from job monitoring
2019-07-23 08:39:50,363 DEBUG [c.c.v.VirtualMachineManagerImpl]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128 ctx-bd656426) (logid:9403bb3e)
Destroying vm VM[User|i-50-264-VM], expunge flag off
2019-07-23 08:39:50,369 DEBUG [c.c.u.d.T.Transaction]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128 ctx-bd656426) (logid:9403bb3e)
Rolling back the transaction: Time = 0 Name = API-Job-Executor-6; called
by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-Transaction.execute:43-Transaction.execute:47-AsyncJobManagerImpl.submitAsyncJob:231-VirtualMachineManagerImpl.stopVmThroughJobQueue:4666-VirtualMachineManagerImpl.advanceStop:1599-VirtualMachineManagerImpl.destroy:1864-VMEntityManagerImpl.destroyVirtualMachine:271-VirtualMachineEntityImpl.destroy:233-UserVmManagerImpl.destroyVm:4580
2019-07-23 08:39:50,370 WARN [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128 ctx-bd656426) (logid:9403bb3e)
Unable to schedule async job for command com.cloud.vm.VmWorkStop,
unexpected exception.
javax.persistence.EntityExistsException: Entity already exists:
at
com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1448)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$1.doInTransaction(AsyncJobManagerImpl.java:235)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$1.doInTransaction(AsyncJobManagerImpl.java:231)
at
com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.java:50)
at com.cloud.utils.db.Transaction.execute(Transaction.java:40)
at com.cloud.utils.db.Transaction.execute(Transaction.java:47)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:231)
at
com.cloud.vm.VirtualMachineManagerImpl.stopVmThroughJobQueue(VirtualMachineManagerImpl.java:4666)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1599)
at
com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1864)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.destroyVirtualMachine(VMEntityManagerImpl.java:271)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.destroy(VirtualMachineEntityImpl.java:233)
at
com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:4580)
at
com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:2787)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy165.destroyVm(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin.execute(DestroyVMCmdByAdmin.java:46)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:583)
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:531)
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 '20130' for key 'PRIMARY'
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
... 59 more
2019-07-23 08:39:50,375 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128) (logid:9403bb3e) Unexpected
exception while executing
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin
com.cloud.utils.exception.CloudRuntimeException: Unable to schedule async
job for command com.cloud.vm.VmWorkStop, unexpected exception.
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:247)
at
com.cloud.vm.VirtualMachineManagerImpl.stopVmThroughJobQueue(VirtualMachineManagerImpl.java:4666)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1599)
at
com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1864)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.destroyVirtualMachine(VMEntityManagerImpl.java:271)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.destroy(VirtualMachineEntityImpl.java:233)
at
com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:4580)
at
com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:2787)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy165.destroyVm(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin.execute(DestroyVMCmdByAdmin.java:46)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:583)
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:531)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-07-23 08:39:50,376 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128) (logid:9403bb3e) Complete async
job-20128, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
to schedule async job for command com.cloud.vm.VmWorkStop, unexpected
exception."}
2019-07-23 08:39:50,377 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128) (logid:9403bb3e) Publish async
job-20128 complete on message bus
2019-07-23 08:39:50,377 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128) (logid:9403bb3e) Wake up jobs
related to job-20128
2019-07-23 08:39:50,377 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128) (logid:9403bb3e) Update db
status for job-20128
2019-07-23 08:39:50,378 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128) (logid:9403bb3e) Wake up jobs
joined with job-20128 and disjoin all subjobs created from job- 20128
2019-07-23 08:39:50,380 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128) (logid:9403bb3e) Done executing
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for job-20128
2019-07-23 08:39:50,380 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-6:ctx-3fb9ca20 job-20128) (logid:9403bb3e) Remove
job-20128 from job monitoring
2019-07-23 08:39:51,348 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-8e2fd6af) (logid:602909a8) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:51,351 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-8e2fd6af ctx-8a953695) (logid:602909a8) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:39:51,360 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-8e2fd6af ctx-8a953695 ctx-41c1bd15) (logid:602909a8)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:53,363 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-07f74f3b) (logid:6a547383) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:53,366 DEBUG [c.c.a.ApiServer]
(qtp2114650936-21:ctx-07f74f3b ctx-31827452) (logid:6a547383) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:39:53,375 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-07f74f3b ctx-31827452 ctx-4044e2db) (logid:6a547383)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:54,327 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-e348b616) (logid:e3ef68cc) Begin cleanup
expired async-jobs
2019-07-23 08:39:54,330 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-e348b616) (logid:e3ef68cc) End cleanup expired
async-jobs
2019-07-23 08:39:55,378 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-f4c248cc) (logid:b2356ead) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:55,386 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-f4c248cc ctx-a73fc2b9) (logid:b2356ead) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:39:55,396 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-f4c248cc ctx-a73fc2b9 ctx-16510da6) (logid:b2356ead)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:57,398 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-cb9e3601) (logid:dc783c14) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:57,401 DEBUG [c.c.a.ApiServer]
(qtp2114650936-21:ctx-cb9e3601 ctx-5016e6c5) (logid:dc783c14) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:39:57,409 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-cb9e3601 ctx-5016e6c5 ctx-68e36013) (logid:dc783c14)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:59,411 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-6fea0c17) (logid:2d4d4b54) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:39:59,414 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-6fea0c17 ctx-00ef113e) (logid:2d4d4b54) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:39:59,422 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-6fea0c17 ctx-00ef113e ctx-f85046c0) (logid:2d4d4b54)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:01,425 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-a269ad1d) (logid:3169993d) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:01,428 DEBUG [c.c.a.ApiServer]
(qtp2114650936-21:ctx-a269ad1d ctx-7a1f1350) (logid:3169993d) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:01,437 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-a269ad1d ctx-7a1f1350 ctx-64842531) (logid:3169993d)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:03,440 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-ecefec86) (logid:804f3dad) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:03,443 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-ecefec86 ctx-bf70065d) (logid:804f3dad) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:03,451 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-ecefec86 ctx-bf70065d ctx-7352af1e) (logid:804f3dad)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:04,326 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-0831b40a) (logid:7a19f7eb) Begin cleanup
expired async-jobs
2019-07-23 08:40:04,329 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-0831b40a) (logid:7a19f7eb) End cleanup expired
async-jobs
2019-07-23 08:40:05,337 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-317aad5b) (logid:47a25006) Zone 1 is ready to launch
secondary storage VM
2019-07-23 08:40:05,416 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-d33b0d84) (logid:72535152) Zone 1 is ready to launch
console proxy
2019-07-23 08:40:05,454 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-b318d0e5) (logid:8e6ac333) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:05,456 DEBUG [c.c.a.ApiServer]
(qtp2114650936-21:ctx-b318d0e5 ctx-1b423ac6) (logid:8e6ac333) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:05,463 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-b318d0e5 ctx-1b423ac6 ctx-d19778ba) (logid:8e6ac333)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:07,466 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-04470417) (logid:e25a360a) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:07,469 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-04470417 ctx-87a9f260) (logid:e25a360a) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:07,478 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-04470417 ctx-87a9f260 ctx-8af5617e) (logid:e25a360a)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:09,480 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-5e1e0780) (logid:2d36d0fc) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:09,484 DEBUG [c.c.a.ApiServer]
(qtp2114650936-21:ctx-5e1e0780 ctx-5786c236) (logid:2d36d0fc) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:09,492 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-5e1e0780 ctx-5786c236 ctx-b34b74bd) (logid:2d36d0fc)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:11,495 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-847299bd) (logid:65aa152d) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:11,497 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-847299bd ctx-7c8e5dc2) (logid:65aa152d) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:11,504 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-847299bd ctx-7c8e5dc2 ctx-7e7a3b5f) (logid:65aa152d)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:13,465 DEBUG [c.c.s.StorageManagerImpl]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Storage pool
garbage collector found 0 templates to clean up in storage pool: Primary1
2019-07-23 08:40:13,469 DEBUG [c.c.s.StorageManagerImpl]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Storage pool
garbage collector found 0 templates to clean up in storage pool: Primary2
2019-07-23 08:40:13,472 DEBUG [c.c.s.StorageManagerImpl]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Secondary
storage garbage collector found 0 templates to cleanup on
template_store_ref for store: Secondary1
2019-07-23 08:40:13,472 DEBUG [c.c.s.StorageManagerImpl]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Secondary
storage garbage collector found 0 snapshots to cleanup on
snapshot_store_ref for store: Secondary1
2019-07-23 08:40:13,473 DEBUG [c.c.s.StorageManagerImpl]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Secondary
storage garbage collector found 0 volumes to cleanup on volume_store_ref
for store: Secondary1
2019-07-23 08:40:13,477 DEBUG [o.a.c.s.v.VolumeObject]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Failed to update
state
com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new
state from Creating via DestroyRequested
at
com.cloud.utils.fsm.StateMachine2.getTransition(StateMachine2.java:108)
at
com.cloud.utils.fsm.StateMachine2.getNextState(StateMachine2.java:94)
at
com.cloud.utils.fsm.StateMachine2.transitTo(StateMachine2.java:124)
at
org.apache.cloudstack.storage.datastore.ObjectInDataStoreManagerImpl.update(ObjectInDataStoreManagerImpl.java:307)
at
org.apache.cloudstack.storage.volume.VolumeObject.processEventOnly(VolumeObject.java:418)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.expungeVolumeAsync(VolumeServiceImpl.java:354)
at
com.cloud.storage.StorageManagerImpl.cleanupStorage(StorageManagerImpl.java:1141)
at
com.cloud.storage.StorageManagerImpl$StorageGarbageCollector.runInContext(StorageManagerImpl.java:1503)
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
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-07-23 08:40:13,478 WARN [c.c.s.StorageManagerImpl]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Unable to
destroy volume 48c9654f-5ea1-439c-b9a5-7001f05ce728
com.cloud.utils.exception.CloudRuntimeException: Failed to update
state:com.cloud.utils.fsm.NoTransitionException: Unable to transition to a
new state from Creating via DestroyRequested
at
org.apache.cloudstack.storage.volume.VolumeObject.processEventOnly(VolumeObject.java:421)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.expungeVolumeAsync(VolumeServiceImpl.java:354)
at
com.cloud.storage.StorageManagerImpl.cleanupStorage(StorageManagerImpl.java:1141)
at
com.cloud.storage.StorageManagerImpl$StorageGarbageCollector.runInContext(StorageManagerImpl.java:1503)
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
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-07-23 08:40:13,485 DEBUG [o.a.c.s.v.VolumeObject]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Failed to update
state
com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new
state from Creating via DestroyRequested
at
com.cloud.utils.fsm.StateMachine2.getTransition(StateMachine2.java:108)
at
com.cloud.utils.fsm.StateMachine2.getNextState(StateMachine2.java:94)
at
com.cloud.utils.fsm.StateMachine2.transitTo(StateMachine2.java:124)
at
org.apache.cloudstack.storage.datastore.ObjectInDataStoreManagerImpl.update(ObjectInDataStoreManagerImpl.java:307)
at
org.apache.cloudstack.storage.volume.VolumeObject.processEventOnly(VolumeObject.java:418)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.expungeVolumeAsync(VolumeServiceImpl.java:354)
at
com.cloud.storage.StorageManagerImpl.cleanupStorage(StorageManagerImpl.java:1141)
at
com.cloud.storage.StorageManagerImpl$StorageGarbageCollector.runInContext(StorageManagerImpl.java:1503)
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
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-07-23 08:40:13,485 WARN [c.c.s.StorageManagerImpl]
(StorageManager-Scavenger-1:ctx-25853e95) (logid:43614fd0) Unable to
destroy volume 463e5e3e-e0c6-46ca-8da9-71299a81283f
com.cloud.utils.exception.CloudRuntimeException: Failed to update
state:com.cloud.utils.fsm.NoTransitionException: Unable to transition to a
new state from Creating via DestroyRequested
at
org.apache.cloudstack.storage.volume.VolumeObject.processEventOnly(VolumeObject.java:421)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.expungeVolumeAsync(VolumeServiceImpl.java:354)
at
com.cloud.storage.StorageManagerImpl.cleanupStorage(StorageManagerImpl.java:1141)
at
com.cloud.storage.StorageManagerImpl$StorageGarbageCollector.runInContext(StorageManagerImpl.java:1503)
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
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-07-23 08:40:13,506 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-99ece2b4) (logid:0afcf3b7) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:13,509 DEBUG [c.c.a.ApiServer]
(qtp2114650936-21:ctx-99ece2b4 ctx-908154b0) (logid:0afcf3b7) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:13,517 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-99ece2b4 ctx-908154b0 ctx-019a60fc) (logid:0afcf3b7)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:14,326 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-843debc9) (logid:2146ffc7) Begin cleanup
expired async-jobs
2019-07-23 08:40:14,329 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-843debc9) (logid:2146ffc7) End cleanup expired
async-jobs
2019-07-23 08:40:14,585 INFO [o.a.c.e.o.NetworkOrchestrator]
(Network-Scavenger-1:ctx-8d9de194) (logid:14742f03) NetworkGarbageCollector
uses '600' seconds for GC interval.
2019-07-23 08:40:14,766 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl]
(ExternalNetworkMonitor-1:ctx-4b58cf57) (logid:3958b4fb) External devices
are not used. Skipping external device usage collection
2019-07-23 08:40:14,775 INFO [c.c.r.ResourceLimitManagerImpl]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Started resource
counters recalculation periodic task.
2019-07-23 08:40:14,776 DEBUG [c.c.s.s.SnapshotSchedulerImpl]
(SnapshotPollTask:ctx-20126a2a) (logid:bd587476) Snapshot scheduler.poll is
being called at 2019-07-23 06:40:14 GMT
2019-07-23 08:40:14,777 DEBUG [c.c.s.s.SnapshotSchedulerImpl]
(SnapshotPollTask:ctx-20126a2a) (logid:bd587476) Got 0 snapshots to be
executed at 2019-07-23 06:40:14 GMT
2019-07-23 08:40:14,778 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterMonitor-1:ctx-03cf0aef) (logid:15e74ba6) Found 0 running routers.
2019-07-23 08:40:14,779 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-b0b0b484) (logid:116d69a1) Found 0 routers to
update status.
2019-07-23 08:40:14,780 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-b0b0b484) (logid:116d69a1) Found 0 VPC networks
to update Redundant State.
2019-07-23 08:40:14,781 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-b0b0b484) (logid:116d69a1) Found 0 networks to
update RvR status.
2019-07-23 08:40:14,797 DEBUG [c.c.s.StatsCollector]
(StatsCollector-5:ctx-0186f0b0) (logid:8b89fcb7) Skipping collect vm disk
stats from hosts
2019-07-23 08:40:14,800 DEBUG [c.c.s.StatsCollector]
(StatsCollector-6:ctx-dc720d51) (logid:dad7014e) Skipping collect vm
network stats from hosts
2019-07-23 08:40:14,806 DEBUG [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Rolling back the
transaction: Time = 3 Name = ResourceCountChecker-1; called by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy41.countCpuNumberAllocatedToAccount:-1-ResourceLimitManagerImpl.countCpusForAccount:932-ResourceLimitManagerImpl.recalculateAccountResourceCount:892-ResourceLimitManagerImpl$3.doInTransaction:855
2019-07-23 08:40:14,808 WARN [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) txn: Commit called
when it is not a transaction:
-Transaction.execute:41-Transaction.execute:47-ResourceLimitManagerImpl.recalculateDomainResourceCount:829-ResourceLimitManagerImpl$ResourceCountCheckTask.runInContext:1058-ManagedContextRunnable$1.run:49-DefaultManagedContext$1.call:56-DefaultManagedContext.callWithContext:103-DefaultManagedContext.runWithContext:53-ManagedContextRunnable.run:46-Executors$RunnableAdapter.call:511-FutureTask.runAndReset:308-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301:180
2019-07-23 08:40:14,811 DEBUG [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Rolling back the
transaction: Time = 3 Name = tx-1265; called by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy41.countMemoryAllocatedToAccount:-1-ResourceLimitManagerImpl.calculateMemoryForAccount:936-ResourceLimitManagerImpl.recalculateAccountResourceCount:894-ResourceLimitManagerImpl$3.doInTransaction:855
2019-07-23 08:40:14,813 WARN [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) txn: Commit called
when it is not a transaction:
-Transaction.execute:41-Transaction.execute:47-ResourceLimitManagerImpl.recalculateDomainResourceCount:829-ResourceLimitManagerImpl$ResourceCountCheckTask.runInContext:1058-ManagedContextRunnable$1.run:49-DefaultManagedContext$1.call:56-DefaultManagedContext.callWithContext:103-DefaultManagedContext.runWithContext:53-ManagedContextRunnable.run:46-Executors$RunnableAdapter.call:511-FutureTask.runAndReset:308-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301:180
2019-07-23 08:40:14,853 DEBUG [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Rolling back the
transaction: Time = 2 Name = tx-1276; called by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy41.countCpuNumberAllocatedToAccount:-1-ResourceLimitManagerImpl.countCpusForAccount:932-ResourceLimitManagerImpl.recalculateAccountResourceCount:892-ResourceLimitManagerImpl$3.doInTransaction:855
2019-07-23 08:40:14,854 WARN [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) txn: Commit called
when it is not a transaction:
-Transaction.execute:41-Transaction.execute:47-ResourceLimitManagerImpl.recalculateDomainResourceCount:829-ResourceLimitManagerImpl$ResourceCountCheckTask.runInContext:1058-ManagedContextRunnable$1.run:49-DefaultManagedContext$1.call:56-DefaultManagedContext.callWithContext:103-DefaultManagedContext.runWithContext:53-ManagedContextRunnable.run:46-Executors$RunnableAdapter.call:511-FutureTask.runAndReset:308-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301:180
2019-07-23 08:40:14,856 DEBUG [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Rolling back the
transaction: Time = 2 Name = tx-1277; called by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy41.countMemoryAllocatedToAccount:-1-ResourceLimitManagerImpl.calculateMemoryForAccount:936-ResourceLimitManagerImpl.recalculateAccountResourceCount:894-ResourceLimitManagerImpl$3.doInTransaction:855
2019-07-23 08:40:14,857 WARN [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) txn: Commit called
when it is not a transaction:
-Transaction.execute:41-Transaction.execute:47-ResourceLimitManagerImpl.recalculateDomainResourceCount:829-ResourceLimitManagerImpl$ResourceCountCheckTask.runInContext:1058-ManagedContextRunnable$1.run:49-DefaultManagedContext$1.call:56-DefaultManagedContext.callWithContext:103-DefaultManagedContext.runWithContext:53-ManagedContextRunnable.run:46-Executors$RunnableAdapter.call:511-FutureTask.runAndReset:308-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301:180
2019-07-23 08:40:14,891 DEBUG [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Rolling back the
transaction: Time = 2 Name = tx-1288; called by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy41.countCpuNumberAllocatedToAccount:-1-ResourceLimitManagerImpl.countCpusForAccount:932-ResourceLimitManagerImpl.recalculateAccountResourceCount:892-ResourceLimitManagerImpl$3.doInTransaction:855
2019-07-23 08:40:14,892 WARN [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) txn: Commit called
when it is not a transaction:
-Transaction.execute:41-Transaction.execute:47-ResourceLimitManagerImpl.recalculateDomainResourceCount:829-ResourceLimitManagerImpl$ResourceCountCheckTask.runInContext:1058-ManagedContextRunnable$1.run:49-DefaultManagedContext$1.call:56-DefaultManagedContext.callWithContext:103-DefaultManagedContext.runWithContext:53-ManagedContextRunnable.run:46-Executors$RunnableAdapter.call:511-FutureTask.runAndReset:308-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301:180
2019-07-23 08:40:14,895 DEBUG [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Rolling back the
transaction: Time = 2 Name = tx-1289; called by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy41.countMemoryAllocatedToAccount:-1-ResourceLimitManagerImpl.calculateMemoryForAccount:936-ResourceLimitManagerImpl.recalculateAccountResourceCount:894-ResourceLimitManagerImpl$3.doInTransaction:855
2019-07-23 08:40:14,896 WARN [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) txn: Commit called
when it is not a transaction:
-Transaction.execute:41-Transaction.execute:47-ResourceLimitManagerImpl.recalculateDomainResourceCount:829-ResourceLimitManagerImpl$ResourceCountCheckTask.runInContext:1058-ManagedContextRunnable$1.run:49-DefaultManagedContext$1.call:56-DefaultManagedContext.callWithContext:103-DefaultManagedContext.runWithContext:53-ManagedContextRunnable.run:46-Executors$RunnableAdapter.call:511-FutureTask.runAndReset:308-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301:180
2019-07-23 08:40:14,927 DEBUG [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Rolling back the
transaction: Time = 2 Name = tx-1300; called by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy41.countCpuNumberAllocatedToAccount:-1-ResourceLimitManagerImpl.countCpusForAccount:932-ResourceLimitManagerImpl.recalculateAccountResourceCount:892-ResourceLimitManagerImpl$3.doInTransaction:855
2019-07-23 08:40:14,928 WARN [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) txn: Commit called
when it is not a transaction:
-Transaction.execute:41-Transaction.execute:47-ResourceLimitManagerImpl.recalculateDomainResourceCount:829-ResourceLimitManagerImpl$ResourceCountCheckTask.runInContext:1058-ManagedContextRunnable$1.run:49-DefaultManagedContext$1.call:56-DefaultManagedContext.callWithContext:103-DefaultManagedContext.runWithContext:53-ManagedContextRunnable.run:46-Executors$RunnableAdapter.call:511-FutureTask.runAndReset:308-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301:180
2019-07-23 08:40:14,931 DEBUG [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) Rolling back the
transaction: Time = 2 Name = tx-1301; called by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy41.countMemoryAllocatedToAccount:-1-ResourceLimitManagerImpl.calculateMemoryForAccount:936-ResourceLimitManagerImpl.recalculateAccountResourceCount:894-ResourceLimitManagerImpl$3.doInTransaction:855
2019-07-23 08:40:14,932 WARN [c.c.u.d.T.Transaction]
(ResourceCountChecker-1:ctx-ff1cf2fe) (logid:5b93affa) txn: Commit called
when it is not a transaction:
-Transaction.execute:41-Transaction.execute:47-ResourceLimitManagerImpl.recalculateDomainResourceCount:829-ResourceLimitManagerImpl$ResourceCountCheckTask.runInContext:1058-ManagedContextRunnable$1.run:49-DefaultManagedContext$1.call:56-DefaultManagedContext.callWithContext:103-DefaultManagedContext.runWithContext:53-ManagedContextRunnable.run:46-Executors$RunnableAdapter.call:511-FutureTask.runAndReset:308-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301:180
2019-07-23 08:40:15,519 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-63389308) (logid:67f9d41a) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:15,522 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-63389308 ctx-a32a5f26) (logid:67f9d41a) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:15,529 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-63389308 ctx-a32a5f26 ctx-85c0b201) (logid:67f9d41a)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:17,531 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-25ac7025) (logid:47bbc53e) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:17,534 DEBUG [c.c.a.ApiServer]
(qtp2114650936-21:ctx-25ac7025 ctx-0b634e9a) (logid:47bbc53e) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:17,542 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-21:ctx-25ac7025 ctx-0b634e9a ctx-420b4fb8) (logid:47bbc53e)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:19,546 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-6d4d72bf) (logid:f878cce5) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:19,550 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-6d4d72bf ctx-a1aba294) (logid:f878cce5) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:19,560 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-6d4d72bf ctx-a1aba294 ctx-51cd4a75) (logid:f878cce5)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=queryAsyncJobResult&jobid=9403bb3e-b884-4deb-8db1-4411bd54eb66&response=json&signature=refQmGX9%2Flofzv%2Bvv5OQGuQl4S4%3D
2019-07-23 08:40:19,737 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-7:null) (logid:) Ping from 20(fr-kvm1)
2019-07-23 08:40:19,737 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) Process host VM state report from
ping process. host: 20
2019-07-23 08:40:19,798 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) Process VM state report. host: 20,
number of records in report: 58
2019-07-23 08:40:19,798 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
260, power state: PowerOn
2019-07-23 08:40:19,800 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 260
2019-07-23 08:40:19,800 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
261, power state: PowerOn
2019-07-23 08:40:19,801 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 261
2019-07-23 08:40:19,801 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
262, power state: PowerOn
2019-07-23 08:40:19,802 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 262
2019-07-23 08:40:19,802 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
266, power state: PowerOn
2019-07-23 08:40:19,803 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 266
2019-07-23 08:40:19,803 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
267, power state: PowerOn
2019-07-23 08:40:19,804 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 267
2019-07-23 08:40:19,804 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
139, power state: PowerOn
2019-07-23 08:40:19,805 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 139
2019-07-23 08:40:19,805 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
268, power state: PowerOn
2019-07-23 08:40:19,807 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 268
2019-07-23 08:40:19,807 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
269, power state: PowerOn
2019-07-23 08:40:19,808 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 269
2019-07-23 08:40:19,808 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
141, power state: PowerOn
2019-07-23 08:40:19,809 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 141
2019-07-23 08:40:19,809 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
271, power state: PowerOn
2019-07-23 08:40:19,810 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 271
2019-07-23 08:40:19,810 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
272, power state: PowerOn
2019-07-23 08:40:19,811 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 272
2019-07-23 08:40:19,811 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
273, power state: PowerOn
2019-07-23 08:40:19,812 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 273
2019-07-23 08:40:19,813 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
274, power state: PowerOn
2019-07-23 08:40:19,814 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 274
2019-07-23 08:40:19,814 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
275, power state: PowerOn
2019-07-23 08:40:19,815 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 275
2019-07-23 08:40:19,815 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
276, power state: PowerOn
2019-07-23 08:40:19,816 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 276
2019-07-23 08:40:19,816 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
277, power state: PowerOn
2019-07-23 08:40:19,817 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 277
2019-07-23 08:40:19,817 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
21, power state: PowerOn
2019-07-23 08:40:19,819 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 21
2019-07-23 08:40:19,819 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
22, power state: PowerOn
2019-07-23 08:40:19,820 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 22
2019-07-23 08:40:19,820 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
278, power state: PowerOn
2019-07-23 08:40:19,821 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 278
2019-07-23 08:40:19,821 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
279, power state: PowerOn
2019-07-23 08:40:19,822 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 279
2019-07-23 08:40:19,822 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
280, power state: PowerOn
2019-07-23 08:40:19,823 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 280
2019-07-23 08:40:19,823 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
281, power state: PowerOn
2019-07-23 08:40:19,825 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 281
2019-07-23 08:40:19,825 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
282, power state: PowerOn
2019-07-23 08:40:19,826 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 282
2019-07-23 08:40:19,826 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
157, power state: PowerOn
2019-07-23 08:40:19,827 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 157
2019-07-23 08:40:19,827 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
161, power state: PowerOn
2019-07-23 08:40:19,828 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 161
2019-07-23 08:40:19,828 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
36, power state: PowerOn
2019-07-23 08:40:19,829 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 36
2019-07-23 08:40:19,829 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
39, power state: PowerOn
2019-07-23 08:40:19,830 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 39
2019-07-23 08:40:19,831 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
40, power state: PowerOn
2019-07-23 08:40:19,832 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 40
2019-07-23 08:40:19,832 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
297, power state: PowerOn
2019-07-23 08:40:19,833 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 297
2019-07-23 08:40:19,833 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
44, power state: PowerOn
2019-07-23 08:40:19,834 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 44
2019-07-23 08:40:19,834 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
301, power state: PowerOn
2019-07-23 08:40:19,835 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 301
2019-07-23 08:40:19,835 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
302, power state: PowerOn
2019-07-23 08:40:19,836 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 302
2019-07-23 08:40:19,836 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
303, power state: PowerOn
2019-07-23 08:40:19,837 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 303
2019-07-23 08:40:19,837 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
304, power state: PowerOn
2019-07-23 08:40:19,838 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 304
2019-07-23 08:40:19,839 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
305, power state: PowerOn
2019-07-23 08:40:19,840 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 305
2019-07-23 08:40:19,840 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
178, power state: PowerOn
2019-07-23 08:40:19,841 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 178
2019-07-23 08:40:19,841 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
306, power state: PowerOn
2019-07-23 08:40:19,842 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 306
2019-07-23 08:40:19,842 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
307, power state: PowerOn
2019-07-23 08:40:19,843 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 307
2019-07-23 08:40:19,843 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
309, power state: PowerOn
2019-07-23 08:40:19,844 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 309
2019-07-23 08:40:19,844 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
316, power state: PowerOn
2019-07-23 08:40:19,845 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 316
2019-07-23 08:40:19,845 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
329, power state: PowerOn
2019-07-23 08:40:19,847 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 329
2019-07-23 08:40:19,847 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
330, power state: PowerOn
2019-07-23 08:40:19,848 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 330
2019-07-23 08:40:19,848 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
203, power state: PowerOn
2019-07-23 08:40:19,849 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 203
2019-07-23 08:40:19,849 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
331, power state: PowerOn
2019-07-23 08:40:19,850 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 331
2019-07-23 08:40:19,850 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
332, power state: PowerOn
2019-07-23 08:40:19,852 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 332
2019-07-23 08:40:19,852 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
334, power state: PowerOn
2019-07-23 08:40:19,853 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 334
2019-07-23 08:40:19,853 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
94, power state: PowerOn
2019-07-23 08:40:19,854 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 94
2019-07-23 08:40:19,854 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
231, power state: PowerOn
2019-07-23 08:40:19,855 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 231
2019-07-23 08:40:19,855 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
103, power state: PowerOn
2019-07-23 08:40:19,856 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 103
2019-07-23 08:40:19,856 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
104, power state: PowerOn
2019-07-23 08:40:19,857 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 104
2019-07-23 08:40:19,857 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
106, power state: PowerOn
2019-07-23 08:40:19,858 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 106
2019-07-23 08:40:19,858 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
108, power state: PowerOn
2019-07-23 08:40:19,859 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 108
2019-07-23 08:40:19,859 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
109, power state: PowerOn
2019-07-23 08:40:19,868 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 109
2019-07-23 08:40:19,868 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
114, power state: PowerOn
2019-07-23 08:40:19,869 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 114
2019-07-23 08:40:19,869 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
115, power state: PowerOn
2019-07-23 08:40:19,871 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 115
2019-07-23 08:40:19,871 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
116, power state: PowerOn
2019-07-23 08:40:19,872 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 116
2019-07-23 08:40:19,872 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
121, power state: PowerOn
2019-07-23 08:40:19,873 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 121
2019-07-23 08:40:19,873 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM state report. host: 20, vm id:
254, power state: PowerOn
2019-07-23 08:40:19,874 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) VM power state does not change, skip
DB writing. vm id: 254
2019-07-23 08:40:19,892 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-7:null) (logid:) Done with process of VM state
report. host: 20
2019-07-23 08:40:20,196 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-f8a0693b) (logid:65156f0e) ===START=== 137.74.35.117
-- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=listVirtualMachines&id=06c72a1a-177d-4331-a38a-17e741688371&response=json&signature=IeUf3Ktv36LcbsbfA6%2FdoAkgALI%3D
2019-07-23 08:40:20,199 DEBUG [c.c.a.ApiServer]
(qtp2114650936-20:ctx-f8a0693b ctx-b1d5af72) (logid:65156f0e) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:40:20,211 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-20:ctx-f8a0693b ctx-b1d5af72 ctx-2909ca1c) (logid:65156f0e)
===END=== 137.74.35.117 -- GET
apikey=Rw-9vSgzHTTbXHcPCcb5pKvRep_WDUoNipIxMKtrK5ozsnql0RztEFjIAaf_ETdHFAeZijTth2WKw8eSeHoQ0g&command=listVirtualMachines&id=06c72a1a-177d-4331-a38a-17e741688371&response=json&signature=IeUf3Ktv36LcbsbfA6%2FdoAkgALI%3D
2019-07-23 08:40:20,226 WARN [c.c.s.ConsoleProxyServlet]
(qtp2114650936-15:null) (logid:) VM 264 lost host info, sending blank
response for console access request
^C
[root@fr-kvm1 management]# echo "" > management-server.log
[root@fr-kvm1 management]# echo "" > management-server.log
[root@fr-kvm1 management]# echo "" > management-server.log
[root@fr-kvm1 management]#
[root@fr-kvm1 management]# echo "" > management-server.log
[root@fr-kvm1 management]# cat management-server.log
2019-07-23 08:46:54,020 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-18:ctx-ef3300e5) (logid:97f536ae) ===START=== 137.74.35.102
-- GET
command=destroyVirtualMachine&response=json&id=d29cc5c3-561f-421b-aa7c-bf2fd45efb23&expunge=true&volumeids=&_=1563864165796
2019-07-23 08:46:54,023 DEBUG [c.c.a.ApiServer]
(qtp2114650936-18:ctx-ef3300e5 ctx-9c7ce7aa) (logid:97f536ae) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:46:54,034 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:f8a3f7b5) Add job-20133
into job monitoring
2019-07-23 08:46:54,036 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp2114650936-18:ctx-ef3300e5 ctx-9c7ce7aa) (logid:97f536ae) submit async
job-20133, details: AsyncJobVO {id:20133, userId: 2, accountId: 2,
instanceType: VirtualMachine, instanceId: 270, cmd:
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","expunge":"true","httpmethod":"GET","ctxStartEventId":"9323","id":"d29cc5c3-561f-421b-aa7c-bf2fd45efb23","volumeids":"","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"d29cc5c3-561f-421b-aa7c-bf2fd45efb23\"}","ctxAccountId":"2","uuid":"d29cc5c3-561f-421b-aa7c-bf2fd45efb23","cmdEventType":"VM.DESTROY","_":"1563864165796"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 279278805450987, completeMsid: null, lastUpdated:
null, lastPolled: null, created: null, removed: null}
2019-07-23 08:46:54,036 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Executing
AsyncJobVO {id:20133, userId: 2, accountId: 2, instanceType:
VirtualMachine, instanceId: 270, cmd:
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin, cmdInfo:
{"response":"json","ctxUserId":"2","expunge":"true","httpmethod":"GET","ctxStartEventId":"9323","id":"d29cc5c3-561f-421b-aa7c-bf2fd45efb23","volumeids":"","ctxDetails":"{\"interface
com.cloud.vm.VirtualMachine\":\"d29cc5c3-561f-421b-aa7c-bf2fd45efb23\"}","ctxAccountId":"2","uuid":"d29cc5c3-561f-421b-aa7c-bf2fd45efb23","cmdEventType":"VM.DESTROY","_":"1563864165796"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 279278805450987, completeMsid: null, lastUpdated:
null, lastPolled: null, created: null, removed: null}
2019-07-23 08:46:54,038 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-18:ctx-ef3300e5 ctx-9c7ce7aa) (logid:97f536ae) ===END===
137.74.35.102 -- GET
command=destroyVirtualMachine&response=json&id=d29cc5c3-561f-421b-aa7c-bf2fd45efb23&expunge=true&volumeids=&_=1563864165796
2019-07-23 08:46:54,048 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
Checking if there are any ongoing snapshots on the ROOT volumes associated
with VM with ID 270
2019-07-23 08:46:54,049 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
Found 1 no. of volumes of type ROOT for vm with VM ID 270
2019-07-23 08:46:54,049 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
Checking status of snapshots for Volume with Volume Id: 314
2019-07-23 08:46:54,049 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
The count of ongoing Snapshots for VM with ID 270 and disk type ROOT is 0
2019-07-23 08:46:54,050 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
Found no ongoing snapshots on volume of type ROOT, for the vm with id 270
2019-07-23 08:46:54,054 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
Sync job-20134 execution on object VmWorkJobQueue.270
2019-07-23 08:46:54,326 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-5e9c8e1c) (logid:7b3c2e7a) Execute sync-queue
item: SyncQueueItemVO {id:4, queueId: 16930, contentType: AsyncJob,
contentId: 20134, lastProcessMsid: 279278805450987, lastprocessNumber: 22,
lastProcessTime: Tue Jul 23 08:46:54 CEST 2019, created: Tue Jul 23
08:46:54 CEST 2019}
2019-07-23 08:46:54,327 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-5e9c8e1c) (logid:7b3c2e7a) Schedule queued
job-20134
2019-07-23 08:46:54,329 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134) (logid:bc130f63) Add
job-20134 into job monitoring
2019-07-23 08:46:54,330 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-f3a12bb6) (logid:551ca8c4) Begin cleanup
expired async-jobs
2019-07-23 08:46:54,332 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134) (logid:1fa50f59)
Executing AsyncJobVO {id:20134, userId: 2, accountId: 2, instanceType:
null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo:
rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAABDnQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 279278805450987, completeMsid: null, lastUpdated:
null, lastPolled: null, created: Tue Jul 23 08:46:54 CEST 2019, removed:
null}
2019-07-23 08:46:54,333 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-f3a12bb6) (logid:551ca8c4) End cleanup expired
async-jobs
2019-07-23 08:46:54,333 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134) (logid:1fa50f59) Run
VM work job: com.cloud.vm.VmWorkStop for VM 270, job origin: 20133
2019-07-23 08:46:54,335 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134 ctx-5f81a85c)
(logid:1fa50f59) Execute VM work job:
com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":270,"handlerName":"VirtualMachineManagerImpl"}
2019-07-23 08:46:54,337 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134 ctx-5f81a85c)
(logid:1fa50f59) VM is already stopped: VM[User|i-56-270-VM]
2019-07-23 08:46:54,337 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134 ctx-5f81a85c)
(logid:1fa50f59) Done executing VM work job:
com.cloud.vm.VmWorkStop{"cleanup":false,"userId":2,"accountId":2,"vmId":270,"handlerName":"VirtualMachineManagerImpl"}
2019-07-23 08:46:54,337 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134 ctx-5f81a85c)
(logid:1fa50f59) Complete async job-20134, jobStatus: SUCCEEDED,
resultCode: 0, result: null
2019-07-23 08:46:54,338 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134 ctx-5f81a85c)
(logid:1fa50f59) Publish async job-20134 complete on message bus
2019-07-23 08:46:54,338 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134 ctx-5f81a85c)
(logid:1fa50f59) Wake up jobs related to job-20134
2019-07-23 08:46:54,338 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134 ctx-5f81a85c)
(logid:1fa50f59) Update db status for job-20134
2019-07-23 08:46:54,338 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134 ctx-5f81a85c)
(logid:1fa50f59) Wake up jobs joined with job-20134 and disjoin all subjobs
created from job- 20134
2019-07-23 08:46:54,343 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134) (logid:1fa50f59)
Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 270, job
origin: 20133
2019-07-23 08:46:54,343 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134) (logid:1fa50f59)
Done executing com.cloud.vm.VmWorkStop for job-20134
2019-07-23 08:46:54,343 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-2:ctx-a90b189c job-20133/job-20134) (logid:1fa50f59)
Remove job-20134 from job monitoring
2019-07-23 08:46:54,352 DEBUG [c.c.v.VirtualMachineManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
Destroying vm VM[User|i-56-270-VM], expunge flag on
2019-07-23 08:46:54,358 DEBUG [c.c.u.d.T.Transaction]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
Rolling back the transaction: Time = 2 Name = API-Job-Executor-8; called
by
-TransactionLegacy.rollback:890-TransactionLegacy.removeUpTo:833-TransactionLegacy.close:657-Transaction.execute:43-Transaction.execute:47-AsyncJobManagerImpl.submitAsyncJob:231-VirtualMachineManagerImpl.stopVmThroughJobQueue:4666-VirtualMachineManagerImpl.advanceStop:1599-VirtualMachineManagerImpl.destroy:1864-VMEntityManagerImpl.destroyVirtualMachine:271-VirtualMachineEntityImpl.destroy:233-UserVmManagerImpl.destroyVm:4580
2019-07-23 08:46:54,359 WARN [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133 ctx-dff5e9e7) (logid:1fa50f59)
Unable to schedule async job for command com.cloud.vm.VmWorkStop,
unexpected exception.
javax.persistence.EntityExistsException: Entity already exists:
at
com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1448)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$1.doInTransaction(AsyncJobManagerImpl.java:235)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$1.doInTransaction(AsyncJobManagerImpl.java:231)
at
com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.java:50)
at com.cloud.utils.db.Transaction.execute(Transaction.java:40)
at com.cloud.utils.db.Transaction.execute(Transaction.java:47)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:231)
at
com.cloud.vm.VirtualMachineManagerImpl.stopVmThroughJobQueue(VirtualMachineManagerImpl.java:4666)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1599)
at
com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1864)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.destroyVirtualMachine(VMEntityManagerImpl.java:271)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.destroy(VirtualMachineEntityImpl.java:233)
at
com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:4580)
at
com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:2787)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy165.destroyVm(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin.execute(DestroyVMCmdByAdmin.java:46)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:583)
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:531)
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 '20135' for key 'PRIMARY'
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native
Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
... 59 more
2019-07-23 08:46:54,364 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Unexpected
exception while executing
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin
com.cloud.utils.exception.CloudRuntimeException: Unable to schedule async
job for command com.cloud.vm.VmWorkStop, unexpected exception.
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.submitAsyncJob(AsyncJobManagerImpl.java:247)
at
com.cloud.vm.VirtualMachineManagerImpl.stopVmThroughJobQueue(VirtualMachineManagerImpl.java:4666)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1599)
at
com.cloud.vm.VirtualMachineManagerImpl.destroy(VirtualMachineManagerImpl.java:1864)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.destroyVirtualMachine(VMEntityManagerImpl.java:271)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.destroy(VirtualMachineEntityImpl.java:233)
at
com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:4580)
at
com.cloud.vm.UserVmManagerImpl.destroyVm(UserVmManagerImpl.java:2787)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy165.destroyVm(Unknown Source)
at
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin.execute(DestroyVMCmdByAdmin.java:46)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:156)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:583)
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:531)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2019-07-23 08:46:54,365 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Complete async
job-20133, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable
to schedule async job for command com.cloud.vm.VmWorkStop, unexpected
exception."}
2019-07-23 08:46:54,365 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Publish async
job-20133 complete on message bus
2019-07-23 08:46:54,365 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Wake up jobs
related to job-20133
2019-07-23 08:46:54,366 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Update db
status for job-20133
2019-07-23 08:46:54,366 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Wake up jobs
joined with job-20133 and disjoin all subjobs created from job- 20133
2019-07-23 08:46:54,369 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Done executing
org.apache.cloudstack.api.command.admin.vm.DestroyVMCmdByAdmin for job-20133
2019-07-23 08:46:54,369 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-8:ctx-26df9ded job-20133) (logid:1fa50f59) Remove
job-20133 from job monitoring
2019-07-23 08:46:57,151 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-19:ctx-fabf770f) (logid:f048f4e3) ===START=== 137.74.35.102
-- GET
command=queryAsyncJobResult&jobId=1fa50f59-9406-4519-ab71-a57de72b41f2&response=json&_=1563864165797
2019-07-23 08:46:57,154 DEBUG [c.c.a.ApiServer]
(qtp2114650936-19:ctx-fabf770f ctx-f99ae360) (logid:f048f4e3) CIDRs from
which account 'Acct[27cd01ef-3907-11e9-87ab-a4bf012ed1a6-admin]' is allowed
to perform API calls: 0.0.0.0/0,::/0
2019-07-23 08:46:57,163 DEBUG [c.c.a.ApiServlet]
(qtp2114650936-19:ctx-fabf770f ctx-f99ae360) (logid:f048f4e3) ===END===
137.74.35.102 -- GET
command=queryAsyncJobResult&jobId=1fa50f59-9406-4519-ab71-a57de72b41f2&response=json&_=1563864165797
2019-07-23 08:47:04,326 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ed323f1b) (logid:ad5ba1f5) Begin cleanup
expired async-jobs
2019-07-23 08:47:04,329 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ed323f1b) (logid:ad5ba1f5) End cleanup expired
async-jobs
2019-07-23 08:47:05,338 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-1809c52a) (logid:74bd0313) Zone 1 is ready to launch
secondary storage VM
2019-07-23 08:47:05,415 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-8df0a7f2) (logid:569fd12f) Zone 1 is ready to launch
console proxy
[root@fr-kvm1 management]#