ISSUE TYPE
COMPONENT NAME
indirect agent load balancing algorithm
CLOUDSTACK VERSION
CONFIGURATION
- Advanced zone configuration with 1 zone, 1 pod, 1 management hosts, 1 KVM hosts, Shared storage (NFS)
- “indirect.agent.lb.algorithm” set to “roundrobin”
- “host” value contains comma separated list of both management servers
- Issue Observed in env with XenServer 6.5sp1 but should not be relevant
OS / ENVIRONMENT
NA
SUMMARY
When SSVM/CPVM is destroyed, it can't be started automatically any more and the following error is shown in the mgmt error log:
2019-11-27 10:11:55,652 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318 ctx-080fa0b0) (logid:d507f5ae) Invocation exception, caused by: java.lang.IndexOutOfBoundsException: fromIndex = -1 2019-11-27 10:11:55,654 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318 ctx-080fa0b0) (logid:d507f5ae) Rethrow exception java.lang.IndexOutOfBoundsException: fromIndex = -1 2019-11-27 10:11:55,654 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 3712, job origin: 17904 2019-11-27 10:11:55,654 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Unable to complete AsyncJobVO {id:18318, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAOgHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 32986472974184, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 27 10:11:54 UTC 2019, removed: null}, job origin:17904 java.lang.IndexOutOfBoundsException: fromIndex = -1 at java.util.SubList.<init>(AbstractList.java:620) at java.util.RandomAccessSubList.<init>(AbstractList.java:775) at java.util.AbstractList.subList(AbstractList.java:484) at org.apache.cloudstack.agent.lb.algorithm.IndirectAgentLBRoundRobinAlgorithm.sort(IndirectAgentLBRoundRobinAlgorithm.java:44) at org.apache.cloudstack.agent.lb.IndirectAgentLBServiceImpl.getManagementServerList(IndirectAgentLBServiceImpl.java:93) at org.apache.cloudstack.secondarystorage.SecondaryStorageManagerImpl.finalizeVirtualMachineProfile(SecondaryStorageManagerImpl.java:1128) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1110) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107) at sun.reflect.GeneratedMethodAccessor233.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5270) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) 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-11-27 10:11:55,655 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Complete async job-18318, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyACNqYXZhLmxhbmcuSW5kZXhPdXRPZkJvdW5kc0V4Y2VwdGlvbgM_xZ_atCsnAgAAeHIAGmphdmEubGFuZy5SdW50aW1lRXhjZXB0aW9unl8GRwo0g-UCAAB4cgATamF2YS5sYW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMABEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZhL2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVudDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgAIdAAOZnJvbUluZGV4ID0gLTF1cgAeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAABpzcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAARJAApsaW5lTnVtYmVyTAAOZGVjbGFyaW5nQ2xhc3NxAH4ABUwACGZpbGVOYW1lcQB-AAVMAAptZXRob2ROYW1lcQB-AAV4cAAAAmx0ABFqYXZhLnV0aWwuU3ViTGlzdHQAEUFic3RyYWN0TGlzdC5qYXZhdAAGPGluaXQ-c3EAfgAMAAADB3QAHWphdmEudXRpbC5SYW5kb21BY2Nlc3NTdWJMaXN0cQB-AA9xAH4AEHNxAH4ADAAAAeR0ABZqYXZhLnV0aWwuQWJzdHJhY3RMaXN0cQB-AA90AAdzdWJMaXN0c3EAfgAMAAAALHQAS29yZy5hcGFjaGUuY2xvdWRzdGFjay5hZ2VudC5sYi5hbGdvcml0aG0uSW5kaXJlY3RBZ2VudExCUm91bmRSb2JpbkFsZ29yaXRobXQAJ0luZGlyZWN0QWdlbnRMQlJvdW5kUm9iaW5BbGdvcml0aG0uamF2YXQABHNvcnRzcQB-AAwAAABddAA5b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmFnZW50LmxiLkluZGlyZWN0QWdlbnRMQlNlcnZpY2VJbXBsdAAfSW5kaXJlY3RBZ2VudExCU2VydmljZUltcGwuamF2YXQAF2dldE1hbmFnZW1lbnRTZXJ2ZXJMaXN0c3EAfgAMAAAEaHQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5zZWNvbmRhcnlzdG9yYWdlLlNlY29uZGFyeVN0b3JhZ2VNYW5hZ2VySW1wbHQAIFNlY29uZGFyeVN0b3JhZ2VNYW5hZ2VySW1wbC5qYXZhdAAdZmluYWxpemVWaXJ0dWFsTWFjaGluZVByb2ZpbGVzcQB-AAwAAARWdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0ABBvcmNoZXN0cmF0ZVN0YXJ0c3EAfgAMAAAT83EAfgAjcQB-ACRxAH4AJXNxAH4ADP____90ACZzdW4ucmVmbGVjdC5HZW5lcmF0ZWRNZXRob2RBY2Nlc3NvcjIzM3B0AAZpbnZva2VzcQB-AAwAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgApc3EAfgAMAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-AClzcQB-AAwAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgAMAAAUlnEAfgAjcQB-ACRxAH4AM3NxAH4ADAAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADAAAAkd0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgAMAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AQ3QAD2NhbGxXaXRoQ29udGV4dHNxAH4ADAAAADVxAH4ARnEAfgBDdAAOcnVuV2l0aENvbnRleHRzcQB-AAwAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-AD9xAH4AQHNxAH4ADAAAAhNxAH4AOnEAfgA7cQB-AEBzcQB-AAwAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-AERzcQB-AAwAAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgBAc3EAfgAMAAAEfXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAMAAACcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AVXEAfgBAc3EAfgAMAAAC7HQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgBAc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AYXg 2019-11-27 10:11:55,658 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Publish async job-18318 complete on message bus 2019-11-27 10:11:55,658 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Wake up jobs related to job-18318 2019-11-27 10:11:55,658 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Update db status for job-18318 2019-11-27 10:11:55,659 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Wake up jobs joined with job-18318 and disjoin all subjobs created from job- 18318 2019-11-27 10:11:55,674 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Done executing com.cloud.vm.VmWorkStart for job-18318 2019-11-27 10:11:55,675 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Remove job-18318 from job monitoring 2019-11-27 10:11:55,684 WARN [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-f2145e12) (logid:6dbadcd6) Exception while trying to start secondary storage vm java.lang.IndexOutOfBoundsException: fromIndex = -1 at java.util.SubList.<init>(AbstractList.java:620) at java.util.RandomAccessSubList.<init>(AbstractList.java:775) at java.util.AbstractList.subList(AbstractList.java:484) at org.apache.cloudstack.agent.lb.algorithm.IndirectAgentLBRoundRobinAlgorithm.sort(IndirectAgentLBRoundRobinAlgorithm.java:44) at org.apache.cloudstack.agent.lb.IndirectAgentLBServiceImpl.getManagementServerList(IndirectAgentLBServiceImpl.java:93) at org.apache.cloudstack.secondarystorage.SecondaryStorageManagerImpl.finalizeVirtualMachineProfile(SecondaryStorageManagerImpl.java:1128) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1110) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107) at sun.reflect.GeneratedMethodAccessor233.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5270) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) 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-11-27 10:11:55,684 INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-f2145e12) (logid:6dbadcd6) Unable to start secondary storage vm for standby capacity, vm id : 3712, will recycle it and start a new one
STEPS TO REPRODUCE
EXPECTED RESULTS
ACTUAL RESULTS
one of those can't be started any more
Setting back the “indirect.agent.lb.algorithm” set to “static” will fix the problem and both SSVM/CPVM will start fine.
ISSUE TYPE
COMPONENT NAME
CLOUDSTACK VERSION
CONFIGURATION
OS / ENVIRONMENT
NA
SUMMARY
When SSVM/CPVM is destroyed, it can't be started automatically any more and the following error is shown in the mgmt error log:
2019-11-27 10:11:55,652 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318 ctx-080fa0b0) (logid:d507f5ae) Invocation exception, caused by: java.lang.IndexOutOfBoundsException: fromIndex = -1 2019-11-27 10:11:55,654 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318 ctx-080fa0b0) (logid:d507f5ae) Rethrow exception java.lang.IndexOutOfBoundsException: fromIndex = -1 2019-11-27 10:11:55,654 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 3712, job origin: 17904 2019-11-27 10:11:55,654 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Unable to complete AsyncJobVO {id:18318, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAOgHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 32986472974184, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 27 10:11:54 UTC 2019, removed: null}, job origin:17904 java.lang.IndexOutOfBoundsException: fromIndex = -1 at java.util.SubList.<init>(AbstractList.java:620) at java.util.RandomAccessSubList.<init>(AbstractList.java:775) at java.util.AbstractList.subList(AbstractList.java:484) at org.apache.cloudstack.agent.lb.algorithm.IndirectAgentLBRoundRobinAlgorithm.sort(IndirectAgentLBRoundRobinAlgorithm.java:44) at org.apache.cloudstack.agent.lb.IndirectAgentLBServiceImpl.getManagementServerList(IndirectAgentLBServiceImpl.java:93) at org.apache.cloudstack.secondarystorage.SecondaryStorageManagerImpl.finalizeVirtualMachineProfile(SecondaryStorageManagerImpl.java:1128) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1110) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107) at sun.reflect.GeneratedMethodAccessor233.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5270) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) 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-11-27 10:11:55,655 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Complete async job-18318, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyACNqYXZhLmxhbmcuSW5kZXhPdXRPZkJvdW5kc0V4Y2VwdGlvbgM_xZ_atCsnAgAAeHIAGmphdmEubGFuZy5SdW50aW1lRXhjZXB0aW9unl8GRwo0g-UCAAB4cgATamF2YS5sYW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMABEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZhL2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVudDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgAIdAAOZnJvbUluZGV4ID0gLTF1cgAeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAABpzcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAARJAApsaW5lTnVtYmVyTAAOZGVjbGFyaW5nQ2xhc3NxAH4ABUwACGZpbGVOYW1lcQB-AAVMAAptZXRob2ROYW1lcQB-AAV4cAAAAmx0ABFqYXZhLnV0aWwuU3ViTGlzdHQAEUFic3RyYWN0TGlzdC5qYXZhdAAGPGluaXQ-c3EAfgAMAAADB3QAHWphdmEudXRpbC5SYW5kb21BY2Nlc3NTdWJMaXN0cQB-AA9xAH4AEHNxAH4ADAAAAeR0ABZqYXZhLnV0aWwuQWJzdHJhY3RMaXN0cQB-AA90AAdzdWJMaXN0c3EAfgAMAAAALHQAS29yZy5hcGFjaGUuY2xvdWRzdGFjay5hZ2VudC5sYi5hbGdvcml0aG0uSW5kaXJlY3RBZ2VudExCUm91bmRSb2JpbkFsZ29yaXRobXQAJ0luZGlyZWN0QWdlbnRMQlJvdW5kUm9iaW5BbGdvcml0aG0uamF2YXQABHNvcnRzcQB-AAwAAABddAA5b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmFnZW50LmxiLkluZGlyZWN0QWdlbnRMQlNlcnZpY2VJbXBsdAAfSW5kaXJlY3RBZ2VudExCU2VydmljZUltcGwuamF2YXQAF2dldE1hbmFnZW1lbnRTZXJ2ZXJMaXN0c3EAfgAMAAAEaHQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5zZWNvbmRhcnlzdG9yYWdlLlNlY29uZGFyeVN0b3JhZ2VNYW5hZ2VySW1wbHQAIFNlY29uZGFyeVN0b3JhZ2VNYW5hZ2VySW1wbC5qYXZhdAAdZmluYWxpemVWaXJ0dWFsTWFjaGluZVByb2ZpbGVzcQB-AAwAAARWdAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0ABBvcmNoZXN0cmF0ZVN0YXJ0c3EAfgAMAAAT83EAfgAjcQB-ACRxAH4AJXNxAH4ADP____90ACZzdW4ucmVmbGVjdC5HZW5lcmF0ZWRNZXRob2RBY2Nlc3NvcjIzM3B0AAZpbnZva2VzcQB-AAwAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgApc3EAfgAMAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-AClzcQB-AAwAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgAMAAAUlnEAfgAjcQB-ACRxAH4AM3NxAH4ADAAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADAAAAkd0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgAMAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AQ3QAD2NhbGxXaXRoQ29udGV4dHNxAH4ADAAAADVxAH4ARnEAfgBDdAAOcnVuV2l0aENvbnRleHRzcQB-AAwAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-AD9xAH4AQHNxAH4ADAAAAhNxAH4AOnEAfgA7cQB-AEBzcQB-AAwAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-AERzcQB-AAwAAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgBAc3EAfgAMAAAEfXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAMAAACcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AVXEAfgBAc3EAfgAMAAAC7HQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgBAc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AYXg 2019-11-27 10:11:55,658 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Publish async job-18318 complete on message bus 2019-11-27 10:11:55,658 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Wake up jobs related to job-18318 2019-11-27 10:11:55,658 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Update db status for job-18318 2019-11-27 10:11:55,659 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Wake up jobs joined with job-18318 and disjoin all subjobs created from job- 18318 2019-11-27 10:11:55,674 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Done executing com.cloud.vm.VmWorkStart for job-18318 2019-11-27 10:11:55,675 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-137:ctx-19e1bf7d job-17904/job-18318) (logid:d507f5ae) Remove job-18318 from job monitoring 2019-11-27 10:11:55,684 WARN [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-f2145e12) (logid:6dbadcd6) Exception while trying to start secondary storage vm java.lang.IndexOutOfBoundsException: fromIndex = -1 at java.util.SubList.<init>(AbstractList.java:620) at java.util.RandomAccessSubList.<init>(AbstractList.java:775) at java.util.AbstractList.subList(AbstractList.java:484) at org.apache.cloudstack.agent.lb.algorithm.IndirectAgentLBRoundRobinAlgorithm.sort(IndirectAgentLBRoundRobinAlgorithm.java:44) at org.apache.cloudstack.agent.lb.IndirectAgentLBServiceImpl.getManagementServerList(IndirectAgentLBServiceImpl.java:93) at org.apache.cloudstack.secondarystorage.SecondaryStorageManagerImpl.finalizeVirtualMachineProfile(SecondaryStorageManagerImpl.java:1128) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1110) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107) at sun.reflect.GeneratedMethodAccessor233.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5270) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) 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-11-27 10:11:55,684 INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-f2145e12) (logid:6dbadcd6) Unable to start secondary storage vm for standby capacity, vm id : 3712, will recycle it and start a new oneSTEPS TO REPRODUCE
EXPECTED RESULTS
ACTUAL RESULTS