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 <[email protected]> Sent: Tuesday, February 21, 2017 1:35 AM To: [email protected] 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
