Hi Nick, The copying tasks/logs are fine and expected. Based on the other logs I see the issue to be related to storage, systemvm template fail to copy where a org.apache.cloudstack.storage.command.CopyCommand fails due to:
DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-285:ctx-9c66884a) (logid:f634882d) Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: d9e3d888-3ace-40dc-9259-5c566537a426 failed due to The uuid you supplied was invalid. WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-285:ctx-9c66884a) (logid:f634882d) Unable to create volume; Pool=volumeTO[uuid=2a9ed594-a59d-4c14-a172-538717e262c2|path=null|datastore=PrimaryDataStoreTO[uuid=52ea3069-22c9-352c-a910-c298b48b3b46|name=null|id=255|pooltype=NetworkFilesystem]]; Disk:- com.cloud.utils.exception.CloudRuntimeException: Catch Exception com.xensource.xenapi.Types$UuidInvalid :VDI getByUuid for uuid: d9e3d888-3ace-40dc-9259-5c566537a426 failed due to The uuid you supplied was invalid. >---at >com.cloud.hypervisor.xenserver.resource.XenServerStorageProcessor.getVDIbyUuid(XenServerStorageProcessor.java:635) >---at >com.cloud.hypervisor.xenserver.resource.XenServerStorageProcessor.cloneVolumeFromBaseTemplate(XenServerStorageProcessor.java:821) Check your secondary and primary storages, are they mounted on all the XenServer/XCP-ng hosts as well as the health/connectivity of the hosts and storage pools. Regards, Rohit Yadav Software Architect, ShapeBlue https://www.shapeblue.com ________________________________ From: Nick Thompson <nick.thomp...@neos.co.nz> Sent: Tuesday, March 3, 2020 08:52 To: 'users@cloudstack.apache.org' <users@cloudstack.apache.org> Subject: RE: Upgrading from 4.11.3 to 4.13 with XCP-NG 7.5 I also noticed the following, I don't know if it is a big problem or not; Copying (xenserver65) 2020-02-27 02:05:41,681 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-8:ctx-f3138956) (logid:47eafe6b) Copying /usr/share/cloudstack-common/scripts/vm/hypervisor/xenserver/xenserver65/../setup_iscsi.sh to /opt/cloud/bin on 10.20.0.60 with permission 0755 2020-02-27 02:05:41,682 DEBUG [c.c.u.s.SSHCmdHelper] (DirectAgent-8:ctx-f3138956) (logid:47eafe6b) Executing cmd: mkdir -m 700 -p /opt/cloud/bin 2020-02-27 02:05:41,916 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-6:ctx-82fa1a01) (logid:cf8e603b) Copying /usr/share/cloudstack-common/scripts/vm/hypervisor/xenserver/xenserver65/../../../../../vms/systemvm.iso to /opt/xensource/packages/iso on 10.20.0.60 with permission 0644 2020-02-27 02:05:41,917 DEBUG [c.c.u.s.SSHCmdHelper] (DirectAgent-6:ctx-82fa1a01) (logid:cf8e603b) Executing cmd: mkdir -m 700 -p /opt/xensource/packages/iso Should it be (xcpserver) Copying /usr/share/cloudstack-common/scripts/vm/hypervisor/xenserver/xcpserver/../setup_iscsi.sh to /opt/cloud/bin on 10.20.0.60 with permission 0755 Regards, Nick. rohit.ya...@shapeblue.com www.shapeblue.com 3 London Bridge Street, 3rd floor, News Building, London SE1 9SGUK @shapeblue -----Original Message----- From: Nick Thompson <nick.thomp...@neos.co.nz> Sent: Tuesday, 3 March 2020 3:55 pm To: 'users@cloudstack.apache.org' <users@cloudstack.apache.org> Subject: RE: Upgrading from 4.11.3 to 4.13 with XCP-NG 7.5 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 <rohit.ya...@shapeblue.com> Sent: Saturday, 29 February 2020 12:21 am To: 'users@cloudstack.apache.org' <users@cloudstack.apache.org> 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 <nick.thomp...@neos.co.nz> Sent: Wednesday, February 26, 2020 20:45 To: 'users@cloudstack.apache.org' <users@cloudstack.apache.org> 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. rohit.ya...@shapeblue.com www.shapeblue.com<http://www.shapeblue.com> 3 London Bridge Street, 3rd floor, News Building, London SE1 9SGUK @shapeblue
