[ 
https://issues.apache.org/jira/browse/CLOUDSTACK-9370?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15259931#comment-15259931
 ] 

ASF GitHub Bot commented on CLOUDSTACK-9370:
--------------------------------------------

Github user prashanthvarma commented on the pull request:

    https://github.com/apache/cloudstack/pull/1356#issuecomment-215041061
  
    @milamberspace @swill @remibergsma @DaanHoogland, I am seeing a similar 
issue on master: https://issues.apache.org/jira/browse/CLOUDSTACK-9370
    
    I have couple of questions regarding this issue:
    Does this PR supposed to fix this issue as well, and is anyone else seeing 
this issue on master ? 
    
    Please excuse me, if this is not the correct platform for such questions. 
Let me know, where I can ask such questions.
    
    Thank you !!


> Failed to create VPC: Unable to start  VPC VR (VM DomainRouter) due to error 
> in finalizeStart, not retrying
> -----------------------------------------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-9370
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-9370
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the 
> default.) 
>          Components: Virtual Router
>    Affects Versions: 4.9.0
>         Environment: Centos El7
> KVM
> NFS (primary/secondary) 
>            Reporter: Mani Prashanth Varma Manthena
>            Priority: Critical
>             Fix For: 4.9.0
>
>
> I am unable to create VPCs on latest cloudstack master due to the following 
> error:
> {noformat}
> 2016-04-27 02:31:09,243 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-f74a2364 ctx-a6b6f0f5) (logid:811ff82e) Returning 
> cached instance of singleton bean 'networkModelImpl'
> 2016-04-27 02:31:09,243 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-f74a2364 ctx-a6b6f0f5) (logid:811ff82e) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public org.apache.cloudstack.alert.AlertService 
> org.apache.cloudstack.api.BaseCmd._alertSvc
> 2016-04-27 02:31:09,243 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-f74a2364 ctx-a6b6f0f5) (logid:811ff82e) Returning 
> cached instance of singleton bean 'alertManagerImpl'
> 2016-04-27 02:31:09,243 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-f74a2364 ctx-a6b6f0f5) (logid:811ff82e) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public com.cloud.utils.db.UUIDManager 
> org.apache.cloudstack.api.BaseCmd._uuidMgr
> 2016-04-27 02:31:09,243 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-f74a2364 ctx-a6b6f0f5) (logid:811ff82e) Returning 
> cached instance of singleton bean 'uUIDManagerImpl'
> 2016-04-27 02:31:09,262 DEBUG [c.c.a.ApiServlet] 
> (catalina-exec-18:ctx-f74a2364 ctx-a6b6f0f5) (logid:811ff82e) ===END===  
> 10.31.56.146 -- GET  
> command=queryAsyncJobResult&jobId=6b2d4faa-4dae-4785-bd5b-cd06696a84da&response=json&_=1461749506662
> 2016-04-27 02:31:09,311 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (AsyncJobMgr-Heartbeat-1:ctx-31d90a22) (logid:a7da00ab) Begin cleanup expired 
> async-jobs
> 2016-04-27 02:31:09,316 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (AsyncJobMgr-Heartbeat-1:ctx-31d90a22) (logid:a7da00ab) End cleanup expired 
> async-jobs
> 2016-04-27 02:31:09,387 DEBUG [c.c.a.t.Request] 
> (AgentManager-Handler-15:null) (logid:) Seq 9-332421947495286162: Processing: 
>  { Ans: , MgmtId: 275619427298304, via: 9, Ver: v1, Flags: 10, 
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
> 2016-04-27 02:31:09,387 DEBUG [c.c.a.t.Request] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Seq 9-332421947495286162: Received:  { Ans: , MgmtId: 
> 275619427298304, via: 9(ovs-2.mvdcvtb16.us.alcatel-lucent.com), Ver: v1, 
> Flags: 10, { StopAnswer } }
> 2016-04-27 02:31:09,387 ERROR [c.c.v.VirtualMachineManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Failed to start instance VM[DomainRouter|r-252-VM]
> com.cloud.utils.exception.ExecutionException: Unable to start  
> VM:2e54aa49-ae38-405d-b1fe-f14b30053ab6 due to error in finalizeStart, not 
> retrying
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1084)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4580)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>         at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at 
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4741)
>         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:471)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:262)
>         at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>         at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>         at java.lang.Thread.run(Thread.java:745)
> 2016-04-27 02:31:09,396 DEBUG [c.c.v.VirtualMachineManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Cleaning up resources for the vm VM[DomainRouter|r-252-VM] 
> in Starting state
> 2016-04-27 02:31:09,402 DEBUG [c.c.a.m.ClusteredAgentAttache] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Seq 9-332421947495286163: Forwarding Seq 
> 9-332421947495286163:  { Cmd , MgmtId: 275619427298304, via: 
> 9(ovs-2.mvdcvtb16.us.alcatel-lucent.com), Ver: v1, Flags: 100011, 
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"r-252-VM","wait":0}}]
>  } to 275619427298560
> 2016-04-27 02:31:09,652 DEBUG [c.c.a.t.Request] 
> (AgentManager-Handler-14:null) (logid:) Seq 9-332421947495286163: Processing: 
>  { Ans: , MgmtId: 275619427298304, via: 9, Ver: v1, Flags: 10, 
> [{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
> 2016-04-27 02:31:09,652 DEBUG [c.c.a.t.Request] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Seq 9-332421947495286163: Received:  { Ans: , MgmtId: 
> 275619427298304, via: 9(ovs-2.mvdcvtb16.us.alcatel-lucent.com), Ver: v1, 
> Flags: 10, { StopAnswer } }
> 2016-04-27 02:31:09,669 DEBUG [c.c.n.g.ControlNetworkGuru] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Released nic: NicProfile[715-252-null-null-null
> 2016-04-27 02:31:09,686 DEBUG [c.c.v.VirtualMachineManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Successfully released network resources for the vm 
> VM[DomainRouter|r-252-VM]
> 2016-04-27 02:31:09,686 DEBUG [c.c.v.VirtualMachineManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Successfully cleanued up resources for the vm 
> VM[DomainRouter|r-252-VM] in Starting state
> 2016-04-27 02:31:09,704 DEBUG [c.c.c.CapacityManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) VM state transitted from :Starting to Stopped with event: 
> OperationFailedvm's original host id: null new host id: null host id before 
> state transition: 9
> 2016-04-27 02:31:09,709 DEBUG [c.c.c.CapacityManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Hosts's actual total CPU: 23100 and CPU after applying 
> overprovisioning: 23100
> 2016-04-27 02:31:09,709 DEBUG [c.c.c.CapacityManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Hosts's actual total RAM: 22296875008 and RAM after applying 
> overprovisioning: 22296875008
> 2016-04-27 02:31:09,709 DEBUG [c.c.c.CapacityManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) release cpu from host: 9, old used: 1500,reserved: 0, actual 
> total: 23100, total with overprovisioning: 23100; new used: 1000,reserved:0; 
> movedfromreserved: false,moveToReserveredfalse
> 2016-04-27 02:31:09,709 DEBUG [c.c.c.CapacityManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) release mem from host: 9, old used: 1342177280,reserved: 0, 
> total: 22296875008; new used: 1073741824,reserved:0; movedfromreserved: 
> false,moveToReserveredfalse
> 2016-04-27 02:31:09,716 ERROR [c.c.v.VmWorkJobHandlerProxy] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Invocation exception, caused by: 
> com.cloud.exception.AgentUnavailableException: Resource [Host:9] is 
> unreachable: Host 9: Unable to start instance due to Unable to start  
> VM:2e54aa49-ae38-405d-b1fe-f14b30053ab6 due to error in finalizeStart, not 
> retrying
> 2016-04-27 02:31:09,716 INFO  [c.c.v.VmWorkJobHandlerProxy] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160 ctx-c31efe73) 
> (logid:6b2d4faa) Rethrow exception 
> com.cloud.exception.AgentUnavailableException: Resource [Host:9] is 
> unreachable: Host 9: Unable to start instance due to Unable to start  
> VM:2e54aa49-ae38-405d-b1fe-f14b30053ab6 due to error in finalizeStart, not 
> retrying
> 2016-04-27 02:31:09,716 DEBUG [c.c.v.VmWorkJobDispatcher] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) Done 
> with run of VM work job: com.cloud.vm.VmWorkStart for VM 252, job origin: 1159
> 2016-04-27 02:31:09,716 ERROR [c.c.v.VmWorkJobDispatcher] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) Unable 
> to complete AsyncJobVO {id:1160, userId: 2, accountId: 2, instanceType: null, 
> instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: 
> rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAA_HQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AA5SZXN0YXJ0TmV0d29ya3QAP3JPMEFCWE55QUJGcVlYWmhMbXhoYm1jdVFtOXZiR1ZoYnMwZ2NvRFZuUHJ1QWdBQldnQUZkbUZzZFdWNGNBRXhw,
>  cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: 
> null, initMsid: 275619427298304, completeMsid: null, lastUpdated: null, 
> lastPolled: null, created: Wed Apr 27 02:30:18 PDT 2016}, job origin:1159
> com.cloud.exception.AgentUnavailableException: Resource [Host:9] is 
> unreachable: Host 9: Unable to start instance due to Unable to start  
> VM:2e54aa49-ae38-405d-b1fe-f14b30053ab6 due to error in finalizeStart, not 
> retrying
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1120)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4580)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>         at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at 
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4741)
>         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:471)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:262)
>         at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>         at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>         at java.lang.Thread.run(Thread.java:745)
> Caused by: com.cloud.utils.exception.ExecutionException: Unable to start  
> VM:2e54aa49-ae38-405d-b1fe-f14b30053ab6 due to error in finalizeStart, not 
> retrying
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1084)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4580)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         ... 18 more
> 2016-04-27 02:31:09,734 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) 
> Complete async job-1160, jobStatus: FAILED, resultCode: 0, result: 
> rO0ABXNyAC1jb20uY2xvdWQuZXhjZXB0aW9uLkFnZW50VW5hdmFpbGFibGVFeGNlcHRpb24AAAAAVk1PdwIAAHhyADBjb20uY2xvdWQuZXhjZXB0aW9uLlJlc291cmNlVW5hdmFpbGFibGVFeGNlcHRpb24AAAAAVk1PfwIAAkoAA19pZEwABl9zY29wZXQAEUxqYXZhL2xhbmcvQ2xhc3M7eHIAImNvbS5jbG91ZC5leGNlcHRpb24uQ2xvdWRFeGNlcHRpb2556I4b8eRExwIAAkwAC2NzRXJyb3JDb2RldAATTGphdmEvbGFuZy9JbnRlZ2VyO0wABmlkTGlzdHQAFUxqYXZhL3V0aWwvQXJyYXlMaXN0O3hyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwc3IALGNvbS5jbG91ZC51dGlscy5leGNlcHRpb24uRXhlY3V0aW9uRXhjZXB0aW9uAAAAAFZNT34CAAFJAAtjc0Vycm9yQ29kZXhxAH4ABnEAfgAOdABkVW5hYmxlIHRvIHN0YXJ0ICBWTToyZTU0YWE0OS1hZTM4LTQwNWQtYjFmZS1mMTRiMzAwNTNhYjYgZHVlIHRvIGVycm9yIGluIGZpbmFsaXplU3RhcnQsIG5vdCByZXRyeWluZ3VyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAAFXNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIABEkACmxpbmVOdW1iZXJMAA5kZWNsYXJpbmdDbGFzc3EAfgAJTAAIZmlsZU5hbWVxAH4ACUwACm1ldGhvZE5hbWVxAH4ACXhwAAAEPHQAJmNvbS5jbG91ZC52bS5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsdAAeVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbC5qYXZhdAAQb3JjaGVzdHJhdGVTdGFydHNxAH4AEgAAEeRxAH4AFHEAfgAVcQB-ABZzcQB-ABL____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgASAAAAOXEAfgAZcQB-ABp0AAZpbnZva2VzcQB-ABIAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAdc3EAfgASAAACXnQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-AB1zcQB-ABIAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgASAAAShXEAfgAUcQB-ABVxAH4AJ3NxAH4AEgAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4AEgAAAip0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-ABIAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-ABIAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgASAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AN3QAD2NhbGxXaXRoQ29udGV4dHNxAH4AEgAAADVxAH4AOnEAfgA3dAAOcnVuV2l0aENvbnRleHRzcQB-ABIAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADNxAH4ANHNxAH4AEgAAAfZxAH4ALnEAfgAvcQB-ADRzcQB-ABIAAAHXdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADhzcQB-ABIAAAEGdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgA0c3EAfgASAAAEeXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgASAAACZ3QALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4ASXEAfgA0c3EAfgASAAAC6XQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgA0c3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAt4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AVXgAAAAAdACuUmVzb3VyY2UgW0hvc3Q6OV0gaXMgdW5yZWFjaGFibGU6IEhvc3QgOTogVW5hYmxlIHRvIHN0YXJ0IGluc3RhbmNlIGR1ZSB0byBVbmFibGUgdG8gc3RhcnQgIFZNOjJlNTRhYTQ5LWFlMzgtNDA1ZC1iMWZlLWYxNGIzMDA1M2FiNiBkdWUgdG8gZXJyb3IgaW4gZmluYWxpemVTdGFydCwgbm90IHJldHJ5aW5ndXEAfgAQAAAAFXNxAH4AEgAABGBxAH4AFHEAfgAVcQB-ABZzcQB-ABIAABHkcQB-ABRxAH4AFXEAfgAWc3EAfgAS_____nEAfgAZcQB-ABpxAH4AG3NxAH4AEgAAADlxAH4AGXEAfgAacQB-AB1zcQB-ABIAAAArcQB-AB9xAH4AIHEAfgAdc3EAfgASAAACXnEAfgAicQB-ACNxAH4AHXNxAH4AEgAAAGtxAH4AJXEAfgAmcQB-ACdzcQB-ABIAABKFcQB-ABRxAH4AFXEAfgAnc3EAfgASAAAAZnEAfgAqcQB-ACtxAH4ALHNxAH4AEgAAAipxAH4ALnEAfgAvcQB-ADBzcQB-ABIAAAAxcQB-ADJxAH4AM3EAfgA0c3EAfgASAAAAOHEAfgA2cQB-ADdxAH4AOHNxAH4AEgAAAGdxAH4AOnEAfgA3cQB-ADtzcQB-ABIAAAA1cQB-ADpxAH4AN3EAfgA9c3EAfgASAAAALnEAfgA_cQB-ADNxAH4ANHNxAH4AEgAAAfZxAH4ALnEAfgAvcQB-ADRzcQB-ABIAAAHXcQB-AEJxAH4AQ3EAfgA4c3EAfgASAAABBnEAfgBFcQB-AEZxAH4ANHNxAH4AEgAABHlxAH4ASHEAfgBJcQB-AEpzcQB-ABIAAAJncQB-AExxAH4ASXEAfgA0c3EAfgASAAAC6XEAfgBOcQB-AE9xAH4ANHEAfgBTeHNyABFqYXZhLmxhbmcuSW50ZWdlchLioKT3gYc4AgABSQAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAABC9c3EAfgBUAAAAAHcEAAAAAHgAAAAAAAAACXZyABNjb20uY2xvdWQuaG9zdC5Ib3N0AnjOn-BFiMkCAAB4cA
> 2016-04-27 02:31:09,736 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) 
> Publish async job-1160 complete on message bus
> 2016-04-27 02:31:09,736 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) Wake 
> up jobs related to job-1160
> 2016-04-27 02:31:09,736 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) Update 
> db status for job-1160
> 2016-04-27 02:31:09,737 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) Wake 
> up jobs joined with job-1160 and disjoin all subjobs created from job- 1160
> 2016-04-27 02:31:09,747 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) Done 
> executing com.cloud.vm.VmWorkStart for job-1160
> 2016-04-27 02:31:09,748 INFO  [o.a.c.f.j.i.AsyncJobMonitor] 
> (Work-Job-Executor-10:ctx-1279b068 job-1159/job-1160) (logid:6b2d4faa) Remove 
> job-1160 from job monitoring
> 2016-04-27 02:31:09,759 WARN  [c.c.n.v.VpcManagerImpl] 
> (API-Job-Executor-80:ctx-b49f0707 job-1159 ctx-d889f49a) (logid:6b2d4faa) 
> Failed to start vpc [VPC [43-test] due to
> com.cloud.exception.AgentUnavailableException: Resource [Host:9] is 
> unreachable: Host 9: Unable to start instance due to Unable to start  
> VM:2e54aa49-ae38-405d-b1fe-f14b30053ab6 due to error in finalizeStart, not 
> retrying
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1120)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4580)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at 
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>         at 
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:606)
>         at 
> com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4741)
>         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:471)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:262)
>         at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>         at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>         at java.lang.Thread.run(Thread.java:745)
> Caused by: com.cloud.utils.exception.ExecutionException: Unable to start  
> VM:2e54aa49-ae38-405d-b1fe-f14b30053ab6 due to error in finalizeStart, not 
> retrying
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1084)
>         at 
> com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4580)
>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>         ... 18 more
> 2016-04-27 02:31:09,760 DEBUG [c.c.n.v.VpcManagerImpl] 
> (API-Job-Executor-80:ctx-b49f0707 job-1159 ctx-d889f49a) (logid:6b2d4faa) 
> Destroying vpc [VPC [43-test] that failed to start
> 2016-04-27 02:31:09,760 DEBUG [c.c.n.v.VpcManagerImpl] 
> (API-Job-Executor-80:ctx-b49f0707 job-1159 ctx-d889f49a) (logid:6b2d4faa) 
> Destroying vpc [VPC [43-test]
> 2016-04-27 02:31:09,761 DEBUG [c.c.n.v.VpcManagerImpl] 
> (API-Job-Executor-80:ctx-b49f0707 job-1159 ctx-d889f49a) (logid:6b2d4faa) 
> Updating VPC [VPC [43-test] with state Inactive as a part of vpc delete
> 2016-04-27 02:31:09,773 DEBUG [c.c.n.v.VpcManagerImpl] 
> (API-Job-Executor-80:ctx-b49f0707 job-1159 ctx-d889f49a) (logid:6b2d4faa) 
> Shutting down vpc [VPC [43-test]
> 2016-04-27 02:31:09,776 DEBUG [c.c.n.r.NetworkHelperImpl] 
> (API-Job-Executor-80:ctx-b49f0707 job-1159 ctx-d889f49a) (logid:6b2d4faa) 
> Attempting to destroy router 252
> 2016-04-27 02:31:09,785 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
> (API-Job-Executor-80:ctx-b49f0707 job-1159 ctx-d889f49a) (logid:6b2d4faa) 
> Sync job-1161 execution on object VmWorkJobQueue.252
> 2016-04-27 02:31:10,229 DEBUG [c.c.a.ApiServlet] 
> (catalina-exec-18:ctx-ede5e896) (logid:5b9128c0) ===START===  10.31.56.146 -- 
> GET  
> command=queryAsyncJobResult&jobId=14d1e7f3-fd92-41c8-8e47-29ae1f90e68d&response=json&_=1461749507661
> 2016-04-27 02:31:10,234 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public com.cloud.configuration.ConfigurationService 
> org.apache.cloudstack.api.BaseCmd._configService
> 2016-04-27 02:31:10,234 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Returning 
> cached instance of singleton bean 'configurationManagerImpl'
> 2016-04-27 02:31:10,234 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public com.cloud.user.AccountService 
> org.apache.cloudstack.api.BaseCmd._accountService
> 2016-04-27 02:31:10,234 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Returning 
> cached instance of singleton bean 'accountManagerImpl'
> 2016-04-27 02:31:10,234 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public com.cloud.vm.UserVmService 
> org.apache.cloudstack.api.BaseCmd._userVmService
> 2016-04-27 02:31:10,234 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Returning 
> cached instance of singleton bean 'userVmManagerImpl'
> 2016-04-27 02:31:10,234 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public com.cloud.server.ManagementService 
> org.apache.cloudstack.api.BaseCmd._mgr
> 2016-04-27 02:31:10,235 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Returning 
> cached instance of singleton bean 'managementServerImpl'
> 2016-04-27 02:31:10,235 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public com.cloud.storage.StorageService 
> org.apache.cloudstack.api.BaseCmd._storageService
> 2016-04-27 02:31:10,235 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Returning 
> cached instance of singleton bean 'storageManagerImpl'
> 2016-04-27 02:31:10,235 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public com.cloud.storage.VolumeApiService 
> org.apache.cloudstack.api.BaseCmd._volumeService
> 2016-04-27 02:31:10,235 DEBUG [o.s.b.f.s.DefaultListableBeanFactory] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Returning 
> cached instance of singleton bean 'volumeApiServiceImpl'
> 2016-04-27 02:31:10,235 DEBUG [o.s.b.f.a.InjectionMetadata] 
> (catalina-exec-18:ctx-ede5e896 ctx-358c2525) (logid:5b9128c0) Processing 
> injected method of bean 
> 'org.apache.cloudstack.api.command.user.job.QueryAsyncJobResultCmd': 
> AutowiredFieldElement for public com.cloud.resource.ResourceService 
> org.apache.cloudstack.api.BaseCmd._resourceService
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to