You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Yuriy Karpel <yu...@karpel.su> on 2017/02/21 07:35:42 UTC
VPC start error
2017-02-21 10:24:41,455 WARN [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Failed to start vpc [VPC [49-isp] due to
com.cloud.utils.exception.CloudRuntimeException: Unable to serialize: Job
is cancelled as it has been blocking others for too long
at
org.apache.cloudstack.framework.jobs.impl.JobSerializerHelper.fromObjectSerializedString(JobSerializerHelper.java:134)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.unmarshallResultObject(AsyncJobManagerImpl.java:719)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:804)
at
com.cloud.network.router.NetworkHelperImpl.start(NetworkHelperImpl.java:270)
at
com.cloud.network.router.NetworkHelperImpl.startVirtualRouter(NetworkHelperImpl.java:349)
at
com.cloud.network.router.NetworkHelperImpl.startRouters(NetworkHelperImpl.java:334)
at
org.cloud.network.router.deployment.RouterDeploymentDefinition.deployVirtualRouter(RouterDeploymentDefinition.java:199)
at
com.cloud.network.element.VpcVirtualRouterElement.implementVpc(VpcVirtualRouterElement.java:159)
at
com.cloud.network.vpc.VpcManagerImpl.startVpc(VpcManagerImpl.java:1202)
at
com.cloud.network.vpc.VpcManagerImpl.startVpc(VpcManagerImpl.java:1174)
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:497)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy149.startVpc(Unknown Source)
at
org.apache.cloudstack.api.command.user.vpc.CreateVPCCmd.execute(CreateVPCCmd.java:160)
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:554)
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:502)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.StreamCorruptedException: invalid stream header: 2686E2B1
at
java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:806)
at java.io.ObjectInputStream.<init>(ObjectInputStream.java:299)
at
org.apache.cloudstack.framework.jobs.impl.JobSerializerHelper.fromObjectSerializedString(JobSerializerHelper.java:128)
... 35 more
2017-02-21 10:24:41,461 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Destroying vpc [VPC [49-isp] that failed to start
2017-02-21 10:24:41,461 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Destroying vpc [VPC [49-isp]
2017-02-21 10:24:41,468 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Updating VPC [VPC [49-isp] with state Inactive as a part of vpc delete
2017-02-21 10:24:41,529 DEBUG [c.c.u.AccountManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Access to [VPC [49-isp] granted to
Acct[adac9b5b-45f4-4297-90c1-b326e3ec42a3-timofey.russkikh] by DomainChecker
2017-02-21 10:24:41,550 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Shutting down vpc [VPC [49-isp]
2017-02-21 10:24:41,565 DEBUG [c.c.n.r.NetworkHelperImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Attempting to destroy router 6163
2017-02-21 10:24:41,583 DEBUG [c.c.u.AccountManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Access to VM[DomainRouter|r-6163-VM] granted to
Acct[adac9b5b-45f4-4297-90c1-b326e3ec42a3-timofey.russkikh] by DomainChecker
2017-02-21 10:24:41,651 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Sync job-84616 execution on object VmWorkJobQueue.6163
2017-02-21 10:24:42,106 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ef2593f0) (logid:57d40490) Execute sync-queue
item: SyncQueueItemVO {id:64930, queueId: 64915, contentType: AsyncJob,
contentId: 84616, lastProcessMsid: 90212275930085, lastprocessNumber: 2,
lastProcessTime: Tue Feb 21 10:24:42 MSK 2017, created: Tue Feb 21 10:24:41
MSK 2017}
2017-02-21 10:24:42,113 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ef2593f0) (logid:57d40490) Schedule queued
job-84616
2017-02-21 10:24:42,131 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:b0b78603) Add
job-84616 into job monitoring
2017-02-21 10:24:42,145 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Executing AsyncJobVO {id:84616, userId: 358, accountId: 376, instanceType:
null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo:
rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAF4AAAAAAAAAWYAAAAAAAAYE3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 90212275930085, completeMsid: null, lastUpdated:
null, lastPolled: null, created: Tue Feb 21 10:24:41 MSK 2017}
2017-02-21 10:24:42,146 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23) Run
VM work job: com.cloud.vm.VmWorkStop for VM 6163, job origin: 84610
2017-02-21 10:24:42,157 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616 ctx-80c524d2)
(logid:8ad82f23) Execute VM work job:
com.cloud.vm.VmWorkStop{"cleanup":false,"userId":358,"accountId":376,"vmId":6163,"handlerName":"VirtualMachineManagerImpl"}
2017-02-21 10:24:42,159 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-bd3f1c2a) (logid:6a00f433) Begin cleanup
expired async-jobs
2017-02-21 10:24:42,181 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616 ctx-80c524d2)
(logid:8ad82f23) Found an outstanding work item for this vm
VM[DomainRouter|r-6163-VM] with state:Starting, work
id:4682f325-eb06-4aa0-9ed4-2803d54a0f86
2017-02-21 10:24:42,183 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616 ctx-80c524d2)
(logid:8ad82f23) Invocation exception, caused by:
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[DomainRouter|r-6163-VM] when it is in state Starting
2017-02-21 10:24:42,183 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616 ctx-80c524d2)
(logid:8ad82f23) Rethrow exception
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[DomainRouter|r-6163-VM] when it is in state Starting
2017-02-21 10:24:42,184 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 6163, job
origin: 84610
2017-02-21 10:24:42,184 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Unable to complete AsyncJobVO {id:84616, userId: 358, accountId: 376,
instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop,
cmdInfo:
rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAF4AAAAAAAAAWYAAAAAAAAYE3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 90212275930085, completeMsid: null, lastUpdated:
null, lastPolled: null, created: Tue Feb 21 10:24:41 MSK 2017}, job
origin:84610
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[DomainRouter|r-6163-VM] when it is in state Starting
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1486)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1427)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:4590)
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:497)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4734)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2017-02-21 10:24:42,195 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-bd3f1c2a) (logid:6a00f433) End cleanup expired
async-jobs
2017-02-21 10:24:42,204 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Complete async job-84616, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AEZXZSBjYW5ub3Qgc3RvcCBWTVtEb21haW5Sb3V0ZXJ8ci02MTYzLVZNXSB3aGVuIGl0IGlzIGluIHN0YXRlIFN0YXJ0aW5ndXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAWc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFeHAAAAXOdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AAthZHZhbmNlU3RvcHNxAH4ADAAABZNxAH4ADnEAfgAPdAAPb3JjaGVzdHJhdGVTdG9wc3EAfgAMAAAR7nEAfgAOcQB-AA9xAH4AEnNxAH4ADP____50ACRzdW4ucmVmbGVjdC5OYXRpdmVNZXRob2RBY2Nlc3NvckltcGx0AB1OYXRpdmVNZXRob2RBY2Nlc3NvckltcGwuamF2YXQAB2ludm9rZTBzcQB-AAwAAAA-cQB-ABVxAH4AFnQABmludm9rZXNxAH4ADAAAACt0AChzdW4ucmVmbGVjdC5EZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsdAAhRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbC5qYXZhcQB-ABlzcQB-AAwAAAHxdAAYamF2YS5sYW5nLnJlZmxlY3QuTWV0aG9kdAALTWV0aG9kLmphdmFxAH4AGXNxAH4ADAAAAGt0ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JzcQB-AAwAABJ-cQB-AA5xAH4AD3EAfgAjc3EAfgAMAAAAZnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9ic3EAfgAMAAACKnQAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHNxAH4ADAAAADF0AD5vcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGUkMXQAG01hbmFnZWRDb250ZXh0UnVubmFibGUuamF2YXQAA3J1bnNxAH4ADAAAADh0AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxzcQB-AAwAAABndABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgAzdAAPY2FsbFdpdGhDb250ZXh0c3EAfgAMAAAANXEAfgA2cQB-ADN0AA5ydW5XaXRoQ29udGV4dHNxAH4ADAAAAC50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AL3EAfgAwc3EAfgAMAAAB9nEAfgAqcQB-ACtxAH4AMHNxAH4ADAAAAf90AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4ANHNxAH4ADAAAAQp0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGFzay5qYXZhcQB-ADBzcQB-AAwAAAR2dAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJzcQB-AAwAAAJpdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgBFcQB-ADBzcQB-AAwAAALpdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-ADBzcgAmamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUxpc3T8DyUxteyOEAIAAUwABGxpc3RxAH4AB3hyACxqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlQ29sbGVjdGlvbhlCAIDLXvceAgABTAABY3QAFkxqYXZhL3V0aWwvQ29sbGVjdGlvbjt4cHNyABNqYXZhLnV0aWwuQXJyYXlMaXN0eIHSHZnHYZ0DAAFJAARzaXpleHAAAAAAdwQAAAAAeHEAfgBReAAAEJp3CAAAAAAAAAAAeA
2017-02-21 10:24:42,210 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Publish async job-84616 complete on message bus
2017-02-21 10:24:42,211 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Wake up jobs related to job-84616
2017-02-21 10:24:42,211 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Update db status for job-84616
2017-02-21 10:24:42,217 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Wake up jobs joined with job-84616 and disjoin all subjobs created from
job- 84616
2017-02-21 10:24:42,238 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Done executing com.cloud.vm.VmWorkStop for job-84616
2017-02-21 10:24:42,248 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Remove job-84616 from job monitoring
2017-02-21 10:24:42,280 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Unexpected
exception while executing
org.apache.cloudstack.api.command.user.vpc.CreateVPCCmd
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[DomainRouter|r-6163-VM] when it is in state Starting
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1486)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1427)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:4590)
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:497)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4734)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2017-02-21 10:24:42,283 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Complete async
job-84610, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"We
cannot stop VM[DomainRouter|r-6163-VM] when it is in state Starting"}
2017-02-21 10:24:42,291 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Publish async
job-84610 complete on message bus
2017-02-21 10:24:42,291 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Wake up jobs
related to job-84610
2017-02-21 10:24:42,291 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Update db
status for job-84610
2017-02-21 10:24:42,297 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Wake up jobs
joined with job-84610 and disjoin all subjobs created from job- 84610
2017-02-21 10:24:42,308 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Done executing
org.apache.cloudstack.api.command.user.vpc.CreateVPCCmd for job-84610
2017-02-21 10:24:42,309 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Remove
job-84610 from job monitoring
Re: VPC start error
Posted by Simon Weller <sw...@ena.com>.
Yuriy,
Can you provide some background to us in addition to your logs?
What ACS version?
Hypervisor type?
Is this production or lab?
Any other info around what you're trying to do?
- Si
________________________________
From: Yuriy Karpel <yu...@karpel.su>
Sent: Tuesday, February 21, 2017 1:35 AM
To: users@cloudstack.apache.org
Subject: VPC start error
2017-02-21 10:24:41,455 WARN [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Failed to start vpc [VPC [49-isp] due to
com.cloud.utils.exception.CloudRuntimeException: Unable to serialize: Job
is cancelled as it has been blocking others for too long
at
org.apache.cloudstack.framework.jobs.impl.JobSerializerHelper.fromObjectSerializedString(JobSerializerHelper.java:134)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl.unmarshallResultObject(AsyncJobManagerImpl.java:719)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:804)
at
com.cloud.network.router.NetworkHelperImpl.start(NetworkHelperImpl.java:270)
at
com.cloud.network.router.NetworkHelperImpl.startVirtualRouter(NetworkHelperImpl.java:349)
at
com.cloud.network.router.NetworkHelperImpl.startRouters(NetworkHelperImpl.java:334)
at
org.cloud.network.router.deployment.RouterDeploymentDefinition.deployVirtualRouter(RouterDeploymentDefinition.java:199)
at
com.cloud.network.element.VpcVirtualRouterElement.implementVpc(VpcVirtualRouterElement.java:159)
at
com.cloud.network.vpc.VpcManagerImpl.startVpc(VpcManagerImpl.java:1202)
at
com.cloud.network.vpc.VpcManagerImpl.startVpc(VpcManagerImpl.java:1174)
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:497)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy149.startVpc(Unknown Source)
at
org.apache.cloudstack.api.command.user.vpc.CreateVPCCmd.execute(CreateVPCCmd.java:160)
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:554)
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:502)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.StreamCorruptedException: invalid stream header: 2686E2B1
at
java.io.ObjectInputStream.readStreamHeader(ObjectInputStream.java:806)
at java.io.ObjectInputStream.<init>(ObjectInputStream.java:299)
at
org.apache.cloudstack.framework.jobs.impl.JobSerializerHelper.fromObjectSerializedString(JobSerializerHelper.java:128)
... 35 more
2017-02-21 10:24:41,461 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Destroying vpc [VPC [49-isp] that failed to start
2017-02-21 10:24:41,461 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Destroying vpc [VPC [49-isp]
2017-02-21 10:24:41,468 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Updating VPC [VPC [49-isp] with state Inactive as a part of vpc delete
2017-02-21 10:24:41,529 DEBUG [c.c.u.AccountManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Access to [VPC [49-isp] granted to
Acct[adac9b5b-45f4-4297-90c1-b326e3ec42a3-timofey.russkikh] by DomainChecker
2017-02-21 10:24:41,550 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Shutting down vpc [VPC [49-isp]
2017-02-21 10:24:41,565 DEBUG [c.c.n.r.NetworkHelperImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Attempting to destroy router 6163
2017-02-21 10:24:41,583 DEBUG [c.c.u.AccountManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Access to VM[DomainRouter|r-6163-VM] granted to
Acct[adac9b5b-45f4-4297-90c1-b326e3ec42a3-timofey.russkikh] by DomainChecker
2017-02-21 10:24:41,651 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610 ctx-b97ae09e) (logid:8ad82f23)
Sync job-84616 execution on object VmWorkJobQueue.6163
2017-02-21 10:24:42,106 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ef2593f0) (logid:57d40490) Execute sync-queue
item: SyncQueueItemVO {id:64930, queueId: 64915, contentType: AsyncJob,
contentId: 84616, lastProcessMsid: 90212275930085, lastprocessNumber: 2,
lastProcessTime: Tue Feb 21 10:24:42 MSK 2017, created: Tue Feb 21 10:24:41
MSK 2017}
2017-02-21 10:24:42,113 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ef2593f0) (logid:57d40490) Schedule queued
job-84616
2017-02-21 10:24:42,131 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:b0b78603) Add
job-84616 into job monitoring
2017-02-21 10:24:42,145 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Executing AsyncJobVO {id:84616, userId: 358, accountId: 376, instanceType:
null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo:
rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAF4AAAAAAAAAWYAAAAAAAAYE3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 90212275930085, completeMsid: null, lastUpdated:
null, lastPolled: null, created: Tue Feb 21 10:24:41 MSK 2017}
2017-02-21 10:24:42,146 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23) Run
VM work job: com.cloud.vm.VmWorkStop for VM 6163, job origin: 84610
2017-02-21 10:24:42,157 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616 ctx-80c524d2)
(logid:8ad82f23) Execute VM work job:
com.cloud.vm.VmWorkStop{"cleanup":false,"userId":358,"accountId":376,"vmId":6163,"handlerName":"VirtualMachineManagerImpl"}
2017-02-21 10:24:42,159 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-bd3f1c2a) (logid:6a00f433) Begin cleanup
expired async-jobs
2017-02-21 10:24:42,181 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616 ctx-80c524d2)
(logid:8ad82f23) Found an outstanding work item for this vm
VM[DomainRouter|r-6163-VM] with state:Starting, work
id:4682f325-eb06-4aa0-9ed4-2803d54a0f86
2017-02-21 10:24:42,183 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616 ctx-80c524d2)
(logid:8ad82f23) Invocation exception, caused by:
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[DomainRouter|r-6163-VM] when it is in state Starting
2017-02-21 10:24:42,183 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616 ctx-80c524d2)
(logid:8ad82f23) Rethrow exception
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[DomainRouter|r-6163-VM] when it is in state Starting
2017-02-21 10:24:42,184 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 6163, job
origin: 84610
2017-02-21 10:24:42,184 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Unable to complete AsyncJobVO {id:84616, userId: 358, accountId: 376,
instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop,
cmdInfo:
rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAF4AAAAAAAAAWYAAAAAAAAYE3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0,
result: null, initMsid: 90212275930085, completeMsid: null, lastUpdated:
null, lastPolled: null, created: Tue Feb 21 10:24:41 MSK 2017}, job
origin:84610
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[DomainRouter|r-6163-VM] when it is in state Starting
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1486)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1427)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:4590)
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:497)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4734)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2017-02-21 10:24:42,195 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-bd3f1c2a) (logid:6a00f433) End cleanup expired
async-jobs
2017-02-21 10:24:42,204 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Complete async job-84616, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AEZXZSBjYW5ub3Qgc3RvcCBWTVtEb21haW5Sb3V0ZXJ8ci02MTYzLVZNXSB3aGVuIGl0IGlzIGluIHN0YXRlIFN0YXJ0aW5ndXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAWc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFeHAAAAXOdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AAthZHZhbmNlU3RvcHNxAH4ADAAABZNxAH4ADnEAfgAPdAAPb3JjaGVzdHJhdGVTdG9wc3EAfgAMAAAR7nEAfgAOcQB-AA9xAH4AEnNxAH4ADP____50ACRzdW4ucmVmbGVjdC5OYXRpdmVNZXRob2RBY2Nlc3NvckltcGx0AB1OYXRpdmVNZXRob2RBY2Nlc3NvckltcGwuamF2YXQAB2ludm9rZTBzcQB-AAwAAAA-cQB-ABVxAH4AFnQABmludm9rZXNxAH4ADAAAACt0AChzdW4ucmVmbGVjdC5EZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsdAAhRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbC5qYXZhcQB-ABlzcQB-AAwAAAHxdAAYamF2YS5sYW5nLnJlZmxlY3QuTWV0aG9kdAALTWV0aG9kLmphdmFxAH4AGXNxAH4ADAAAAGt0ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JzcQB-AAwAABJ-cQB-AA5xAH4AD3EAfgAjc3EAfgAMAAAAZnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9ic3EAfgAMAAACKnQAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHNxAH4ADAAAADF0AD5vcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGUkMXQAG01hbmFnZWRDb250ZXh0UnVubmFibGUuamF2YXQAA3J1bnNxAH4ADAAAADh0AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxzcQB-AAwAAABndABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgAzdAAPY2FsbFdpdGhDb250ZXh0c3EAfgAMAAAANXEAfgA2cQB-ADN0AA5ydW5XaXRoQ29udGV4dHNxAH4ADAAAAC50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AL3EAfgAwc3EAfgAMAAAB9nEAfgAqcQB-ACtxAH4AMHNxAH4ADAAAAf90AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4ANHNxAH4ADAAAAQp0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGFzay5qYXZhcQB-ADBzcQB-AAwAAAR2dAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJzcQB-AAwAAAJpdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgBFcQB-ADBzcQB-AAwAAALpdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-ADBzcgAmamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUxpc3T8DyUxteyOEAIAAUwABGxpc3RxAH4AB3hyACxqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlQ29sbGVjdGlvbhlCAIDLXvceAgABTAABY3QAFkxqYXZhL3V0aWwvQ29sbGVjdGlvbjt4cHNyABNqYXZhLnV0aWwuQXJyYXlMaXN0eIHSHZnHYZ0DAAFJAARzaXpleHAAAAAAdwQAAAAAeHEAfgBReAAAEJp3CAAAAAAAAAAAeA
2017-02-21 10:24:42,210 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Publish async job-84616 complete on message bus
2017-02-21 10:24:42,211 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Wake up jobs related to job-84616
2017-02-21 10:24:42,211 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Update db status for job-84616
2017-02-21 10:24:42,217 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Wake up jobs joined with job-84616 and disjoin all subjobs created from
job- 84616
2017-02-21 10:24:42,238 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Done executing com.cloud.vm.VmWorkStop for job-84616
2017-02-21 10:24:42,248 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-2:ctx-4a28f6fb job-84610/job-84616) (logid:8ad82f23)
Remove job-84616 from job monitoring
2017-02-21 10:24:42,280 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Unexpected
exception while executing
org.apache.cloudstack.api.command.user.vpc.CreateVPCCmd
com.cloud.utils.exception.CloudRuntimeException: We cannot stop
VM[DomainRouter|r-6163-VM] when it is in state Starting
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1486)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1427)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:4590)
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:497)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4734)
at
com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2017-02-21 10:24:42,283 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Complete async
job-84610, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"We
cannot stop VM[DomainRouter|r-6163-VM] when it is in state Starting"}
2017-02-21 10:24:42,291 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Publish async
job-84610 complete on message bus
2017-02-21 10:24:42,291 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Wake up jobs
related to job-84610
2017-02-21 10:24:42,291 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Update db
status for job-84610
2017-02-21 10:24:42,297 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Wake up jobs
joined with job-84610 and disjoin all subjobs created from job- 84610
2017-02-21 10:24:42,308 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Done executing
org.apache.cloudstack.api.command.user.vpc.CreateVPCCmd for job-84610
2017-02-21 10:24:42,309 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-1:ctx-35f691c4 job-84610) (logid:8ad82f23) Remove
job-84610 from job monitoring