Hi Rohit,
Thanks for looking at this.
I have tried destroying the old ssvm and cpvm, they were automatically created
again by CloudStack with version 4.11.3 of the systemvm. (as the same systemvm
template for CS 4.13 is used for CS 4.11.3)
An example of it not starting a cpvm is on line 99482.
Yes from the logs it looks like the systemvm.iso and scripts were copied to the
xcp-ng hosts (you can see on line 206163), however as mentioned before the
systemvm.iso is the same as the previous version anyway.
I did remove the host flags manually at the time to try and have it copy the
artifacts again (should see this in the log)
Regards,
Nick.
-----------
Example of finalize start. Cpvm not starting
2020-02-27 01:08:48,826 DEBUG [c.c.a.m.AgentManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Details from executing class com.cloud.agent.api.StopCommand:
Stop VM r-2427-VM Succeed
2020-02-27 01:08:48,827 ERROR [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Failed to start instance VM[DomainRouter|r-2427-VM]
com.cloud.utils.exception.ExecutionException: Unable to start
VM:047002a8-a156-48f3-a72c-47a1fb0461bb due to error in finalizeStart, not
retrying
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1211)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
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)
2020-02-27 01:08:48,833 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Cleaning up resources for the vm VM[DomainRouter|r-2427-VM] in
Starting state
2020-02-27 01:08:48,836 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Seq 68-4304315343859353608: Sending { Cmd , MgmtId:
226842157555374, via: 68(c3vz2.c1.p0.wn.test.com), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"r-2427-VM","executeInSequence":false,"wait":0}}]
}
2020-02-27 01:08:48,836 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Seq 68-4304315343859353608: Executing: { Cmd , MgmtId:
226842157555374, via: 68(c3vz2.c1.p0.wn.test.com), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"r-2427-VM","executeInSequence":false,"wait":0}}]
}
2020-02-27 01:08:48,837 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-66:ctx-a8210f13) (logid:086701ee) Seq 68-4304315343859353608:
Executing request
2020-02-27 01:08:48,840 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-66:ctx-a8210f13) (logid:3d074b24) Seq 68-4304315343859353608:
Response Received:
2020-02-27 01:08:48,840 DEBUG [c.c.a.t.Request] (DirectAgent-66:ctx-a8210f13)
(logid:3d074b24) Seq 68-4304315343859353608: Processing: { Ans: , MgmtId:
226842157555374, via: 68(c3vz2.c1.p0.wn.test.com), Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not
exist","wait":0}}] }
2020-02-27 01:08:48,840 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Seq 68-4304315343859353608: Received: { Ans: , MgmtId:
226842157555374, via: 68(c3vz2.c1.p0.wn.test.com), Ver: v1, Flags: 10, {
StopAnswer } }
2020-02-27 01:08:48,875 DEBUG [c.c.n.g.ControlNetworkGuru]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Released nic: NicProfile[6910-2427-null-null-null
2020-02-27 01:08:48,897 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Service SecurityGroup is not supported in the network id=394
2020-02-27 01:08:48,911 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Asking VpcVirtualRouter to release
NicProfile[6913-2427-7d082301-242c-422e-acb2-a621b52c2746-10.30.0.1-null
2020-02-27 01:08:48,917 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Successfully released network resources for the vm
VM[DomainRouter|r-2427-VM]
2020-02-27 01:08:48,917 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Successfully cleaned up resources for the VM
VM[DomainRouter|r-2427-VM] in Starting state
2020-02-27 01:08:48,932 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) VM state transitted from :Starting to Stopped with event:
OperationFailedvm's original host id: null new host id: null host id before
state transition: 68
2020-02-27 01:08:48,937 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Hosts's actual total CPU: 72632 and CPU after applying
overprovisioning: 290528
2020-02-27 01:08:48,937 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Hosts's actual total RAM: 519867087488 and RAM after applying
overprovisioning: 519867072512
2020-02-27 01:08:48,937 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) release cpu from host: 68, old used: 88500,reserved: 0, actual
total: 72632, total with overprovisioning: 290528; new used: 88000,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2020-02-27 01:08:48,937 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) release mem from host: 68, old used: 205474758656,reserved: 0,
total: 519867072512; new used: 205071056896,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2020-02-27 01:08:48,943 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Invocation exception, caused by:
com.cloud.exception.AgentUnavailableException: Resource [Host:68] is
unreachable: Host 68: Unable to start instance due to Unable to start
VM:047002a8-a156-48f3-a72c-47a1fb0461bb due to error in finalizeStart, not
retrying
2020-02-27 01:08:48,943 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675 ctx-4bc1329c)
(logid:3d074b24) Rethrow exception
com.cloud.exception.AgentUnavailableException: Resource [Host:68] is
unreachable: Host 68: Unable to start instance due to Unable to start
VM:047002a8-a156-48f3-a72c-47a1fb0461bb due to error in finalizeStart, not
retrying
2020-02-27 01:08:48,943 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24) Done
with run of VM work job: com.cloud.vm.VmWorkStart for VM 2427, job origin: 27674
2020-02-27 01:08:48,944 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24) Unable
to complete AsyncJobVO {id:27675, userId: 2, accountId: 2, instanceType: null,
instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAJe3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAJ0AA5Sb2xsaW5nUmVzdGFydHQAP3JPMEFCWE55QUJGcVlYWmhMbXhoYm1jdVFtOXZiR1ZoYnMwZ2NvRFZuUHJ1QWdBQldnQUZkbUZzZFdWNGNBRXQADlJlc3RhcnROZXR3b3JrdAA_ck8wQUJYTnlBQkZxWVhaaExteGhibWN1UW05dmJHVmhiczBnY29EVm5QcnVBZ0FCV2dBRmRtRnNkV1Y0Y0FFeHA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 226842157555374, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Thu Feb 27 01:08:16 NZDT 2020, removed: null}, job
origin:27674
com.cloud.exception.AgentUnavailableException: Resource [Host:68] is
unreachable: Host 68: Unable to start instance due to Unable to start
VM:047002a8-a156-48f3-a72c-47a1fb0461bb due to error in finalizeStart, not
retrying
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1247)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
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)
Caused by: com.cloud.utils.exception.ExecutionException: Unable to start
VM:047002a8-a156-48f3-a72c-47a1fb0461bb due to error in finalizeStart, not
retrying
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1211)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
... 18 more
2020-02-27 01:08:48,966 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24)
Complete async job-27675, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyAC1jb20uY2xvdWQuZXhjZXB0aW9uLkFnZW50VW5hdmFpbGFibGVFeGNlcHRpb24AAAAAVk1PdwIAAHhyADBjb20uY2xvdWQuZXhjZXB0aW9uLlJlc291cmNlVW5hdmFpbGFibGVFeGNlcHRpb24AAAAAVk1PfwIAAkoAA19pZEwABl9zY29wZXQAEUxqYXZhL2xhbmcvQ2xhc3M7eHIAImNvbS5jbG91ZC5leGNlcHRpb24uQ2xvdWRFeGNlcHRpb2556I4b8eRExwIAAkwAC2NzRXJyb3JDb2RldAATTGphdmEvbGFuZy9JbnRlZ2VyO0wABmlkTGlzdHQAFUxqYXZhL3V0aWwvQXJyYXlMaXN0O3hyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwc3IALGNvbS5jbG91ZC51dGlscy5leGNlcHRpb24uRXhlY3V0aW9uRXhjZXB0aW9uAAAAAFZNT34CAAFJAAtjc0Vycm9yQ29kZXhxAH4ABnEAfgAOdABkVW5hYmxlIHRvIHN0YXJ0ICBWTTowNDcwMDJhOC1hMTU2LTQ4ZjMtYTcyYy00N2ExZmIwNDYxYmIgZHVlIHRvIGVycm9yIGluIGZpbmFsaXplU3RhcnQsIG5vdCByZXRyeWluZ3VyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAAFXNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIABEkACmxpbmVOdW1iZXJMAA5kZWNsYXJpbmdDbGFzc3EAfgAJTAAIZmlsZU5hbWVxAH4ACUwACm1ldGhvZE5hbWVxAH4ACXhwAAAEu3QAJmNvbS5jbG91ZC52bS5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsdAAeVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbC5qYXZhdAAQb3JjaGVzdHJhdGVTdGFydHNxAH4AEgAAE_NxAH4AFHEAfgAVcQB-ABZzcQB-ABL____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgASAAAAPnEAfgAZcQB-ABp0AAZpbnZva2VzcQB-ABIAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAdc3EAfgASAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-AB1zcQB-ABIAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgASAAAUlnEAfgAUcQB-ABVxAH4AJ3NxAH4AEgAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4AEgAAAkd0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-ABIAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-ABIAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgASAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AN3QAD2NhbGxXaXRoQ29udGV4dHNxAH4AEgAAADVxAH4AOnEAfgA3dAAOcnVuV2l0aENvbnRleHRzcQB-ABIAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADNxAH4ANHNxAH4AEgAAAhNxAH4ALnEAfgAvcQB-ADRzcQB-ABIAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADhzcQB-ABIAAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgA0c3EAfgASAAAEfXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgASAAACcHQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4ASXEAfgA0c3EAfgASAAAC7HQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgA0c3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAt4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AVXgAAAAAdACwUmVzb3VyY2UgW0hvc3Q6NjhdIGlzIHVucmVhY2hhYmxlOiBIb3N0IDY4OiBVbmFibGUgdG8gc3RhcnQgaW5zdGFuY2UgZHVlIHRvIFVuYWJsZSB0byBzdGFydCAgVk06MDQ3MDAyYTgtYTE1Ni00OGYzLWE3MmMtNDdhMWZiMDQ2MWJiIGR1ZSB0byBlcnJvciBpbiBmaW5hbGl6ZVN0YXJ0LCBub3QgcmV0cnlpbmd1cQB-ABAAAAAVc3EAfgASAAAE33EAfgAUcQB-ABVxAH4AFnNxAH4AEgAAE_NxAH4AFHEAfgAVcQB-ABZzcQB-ABL____-cQB-ABlxAH4AGnEAfgAbc3EAfgASAAAAPnEAfgAZcQB-ABpxAH4AHXNxAH4AEgAAACtxAH4AH3EAfgAgcQB-AB1zcQB-ABIAAAHycQB-ACJxAH4AI3EAfgAdc3EAfgASAAAAa3EAfgAlcQB-ACZxAH4AJ3NxAH4AEgAAFJZxAH4AFHEAfgAVcQB-ACdzcQB-ABIAAABmcQB-ACpxAH4AK3EAfgAsc3EAfgASAAACR3EAfgAucQB-AC9xAH4AMHNxAH4AEgAAADFxAH4AMnEAfgAzcQB-ADRzcQB-ABIAAAA4cQB-ADZxAH4AN3EAfgA4c3EAfgASAAAAZ3EAfgA6cQB-ADdxAH4AO3NxAH4AEgAAADVxAH4AOnEAfgA3cQB-AD1zcQB-ABIAAAAucQB-AD9xAH4AM3EAfgA0c3EAfgASAAACE3EAfgAucQB-AC9xAH4ANHNxAH4AEgAAAf9xAH4AQnEAfgBDcQB-ADhzcQB-ABIAAAEKcQB-AEVxAH4ARnEAfgA0c3EAfgASAAAEfXEAfgBIcQB-AElxAH4ASnNxAH4AEgAAAnBxAH4ATHEAfgBJcQB-ADRzcQB-ABIAAALscQB-AE5xAH4AT3EAfgA0cQB-AFN4c3IAEWphdmEubGFuZy5JbnRlZ2VyEuKgpPeBhzgCAAFJAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAEL1zcQB-AFQAAAAAdwQAAAAAeAAAAAAAAABEdnIAE2NvbS5jbG91ZC5ob3N0Lkhvc3QZ15HHlDIdqwIAAHhw
2020-02-27 01:08:48,967 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24) Publish
async job-27675 complete on message bus
2020-02-27 01:08:48,967 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24) Wake up
jobs related to job-27675
2020-02-27 01:08:48,967 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24) Update
db status for job-27675
2020-02-27 01:08:48,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24) Wake up
jobs joined with job-27675 and disjoin all subjobs created from job- 27675
2020-02-27 01:08:48,978 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24) Done
executing com.cloud.vm.VmWorkStart for job-27675
2020-02-27 01:08:48,979 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-9:ctx-5aa39392 job-27674/job-27675) (logid:3d074b24) Remove
job-27675 from job monitoring
2020-02-27 01:08:48,988 DEBUG [c.c.n.v.VpcManagerImpl]
(API-Job-Executor-9:ctx-2dbed11b job-27674 ctx-d8f0f89b) (logid:3d074b24)
Updating VPC [VPC [56-NhVPC] with restartRequired=false
2020-02-27 01:08:48,999 WARN [o.a.c.a.c.u.v.RestartVPCCmd]
(API-Job-Executor-9:ctx-2dbed11b job-27674 ctx-d8f0f89b) (logid:3d074b24)
Exception:
com.cloud.exception.AgentUnavailableException: Resource [Host:68] is
unreachable: Host 68: Unable to start instance due to Unable to start
VM:047002a8-a156-48f3-a72c-47a1fb0461bb due to error in finalizeStart, not
retrying
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1247)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
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)
Caused by: com.cloud.utils.exception.ExecutionException: Unable to start
VM:047002a8-a156-48f3-a72c-47a1fb0461bb due to error in finalizeStart, not
retrying
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1211)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5107)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
... 18 more
2020-02-27 01:08:49,000 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-9:ctx-2dbed11b job-27674) (logid:3d074b24) Complete async
job-27674, jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":534,"errortext":"Resource
[Host:68] is unreachable: Host 68: Unable to start instance due to Unable to
start VM:047002a8-a156-48f3-a72c-47a1fb0461bb due to error in finalizeStart,
not retrying"}
2020-02-27 01:08:49,001 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-9:ctx-2dbed11b job-27674) (logid:3d074b24) Publish async
job-27674 complete on message bus
2020-02-27 01:08:49,001 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-9:ctx-2dbed11b job-27674) (logid:3d074b24) Wake up jobs
related to job-27674
2020-02-27 01:08:49,001 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-9:ctx-2dbed11b job-27674) (logid:3d074b24) Update db status
for job-27674
2020-02-27 01:08:49,002 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-9:ctx-2dbed11b job-27674) (logid:3d074b24) Wake up jobs
joined with job-27674 and disjoin all subjobs created from job- 27674
2020-02-27 01:08:49,008 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-9:ctx-2dbed11b job-27674) (logid:3d074b24) Done executing
org.apache.cloudstack.api.command.user.vpc.RestartVPCCmd for job-27674
2020-02-27 01:08:49,008 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-9:ctx-2dbed11b job-27674) (logid:3d074b24) Remove job-27674
from job monitoring
2020-02-27 01:08:49,131 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-70:ctx-72fbe8d7) (logid:0b24ea90) Seq 71-2954079880578337857:
Response Received:
2020-02-27 01:08:49,131 DEBUG [c.c.a.t.Request] (DirectAgent-70:ctx-72fbe8d7)
(logid:0b24ea90) Seq 71-2954079880578337857: Processing: { Ans: , MgmtId:
226842157555374, via: 71(c3vz1.c1.p0.wn.test.com), Ver: v1, Flags: 110,
[{"com.cloud.agent.api.CheckS2SVpnConnectionsAnswer":{"ipToConnected":{"202.56.44.206":true,"202.56.44.62":true},"ipToDetail":{"202.56.44.206":"IPsec
SA found;Site-to-site VPN have connected","202.56.44.62":"IPsec SA
found;Site-to-site VPN have connected"},"details":"202.56.44.62:0:IPsec SA
found;Site-to-site VPN have connected&202.56.44.206:0:IPsec SA
found;Site-to-site VPN have connected&","result":true,"wait":0}}] }
2020-02-27 01:08:49,131 DEBUG [c.c.a.m.AgentAttache]
(DirectAgent-70:ctx-72fbe8d7) (logid:0b24ea90) Seq 71-2954079880578337857: No
more commands found
-----Original Message-----
From: Rohit Yadav <[email protected]>
Sent: Saturday, 29 February 2020 12:21 am
To: '[email protected]' <[email protected]>
Subject: Re: Upgrading from 4.11.3 to 4.13 with XCP-NG 7.5
Hi Nick,
Can you try destroying old ssvms, cpvms? Then, can you share the management
server logs (at /var/log/cloudstack/management/management-server.log) around
the exceptions/errors?
After upgrading did CloudStack copy systemvm.iso and scripts to the xcp-ng
hosts? You can force this by:
1. Clearing the host tags on hosts:
# for host in $(xe host-list | grep ^uuid | awk '{print $NF}') ; do xe
host-param-clear uuid=$host param-name=tags; done;
2. Restart management server, on reconnecting to xs/xcp-ng hosts it will
copy the artifacts (systemvm.iso, scripts etc, see in the logs)
3. Destroy old VRs and CPVM
Regards,
Rohit Yadav
Software Architect, ShapeBlue
https://www.shapeblue.com
________________________________
From: Nick Thompson <[email protected]>
Sent: Wednesday, February 26, 2020 20:45
To: '[email protected]' <[email protected]>
Subject: Upgrading from 4.11.3 to 4.13 with XCP-NG 7.5
Hi All,
Just wondering if there are any known problems upgrading to the latest version
of CloudStack (4.13) when using XCP-NG 7.5? (working fine in 4.11.3)
For some reason the SystemVMs (Storage and Console Proxy) cloud agent doesn't
start, when running a "service cloud start" it seems to failed with message
'failed at step CHROOT.
The Virtual Routers fail to start (start up and then power off) with the
message "cloudstack Unable to start instance due to Unable to start due to
error in finalizeStart, not retrying" inside the management server log.
Telnetting to port 8250 on the management server seems to be fine on all system
VMs.
Any thoughts on this would be greatly apricated.
Regards,
Nick.
[email protected]
www.shapeblue.com
3 London Bridge Street, 3rd floor, News Building, London SE1 9SGUK @shapeblue
