You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Antoine Boucher <an...@haltondc.com> on 2023/02/21 05:10:46 UTC

Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM (and VRs) of the first zone upgraded without issues but the system VMs (s-318-VM and v-317-VM) of the second zone (Kitchener1) are no longer able to establish connection with the management server.  I have rebooted the host they are on, deleted the system vm to be recreated, I also logged into the two system VM and found nothing so far except fo the following management server logs:

2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM 
2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM

The host of these 2 system VM was missed in the original update, such that is was updated after the Management Server was running with 4.17.2 instead of before.

Would anyone have suggestion to resolve the issue?





2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373322: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer } }
2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state transited from [Starting] to [Running] with event [OperationSucceeded]. VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, host before state transition: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}
2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name":"s-318-VM","Control":"169.254.254.63","Storage":"10.91.6.249","Public":"64.32.40.68","Management":"10.91.0.244","router.ip":"169.254.254.63"},"wait":"60","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Start completed for VM VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"}
2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"VirtualMachineManagerImpl"}
2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job origin: 20367
2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Remove job-20401 from job monitoring
2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm alert
2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up, zone: Kitchener1, secStorageVm: s-318-VM, public 
2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19] dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68, private IP: 10.91.0.244].
2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87", type="SecondaryStorageVm"} was started.
2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is not even started, wait until next turn
2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name":"v-317-VM","Control":"169.254.21.136","Public":"64.32.40.66","Management":"10.91.0.237","router.ip":"169.254.21.136"},"wait":"60","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978: Executing request
2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978: Response Received: 
2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId: 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682: Executing request
2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682: Response Received: 
2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId: 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"VirtualMachineManagerImpl"}
2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId: 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job origin: 20366
2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Remove job-20400 from job monitoring
2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is started
2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"290","_loadInfo":"{
  "connections": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone: Kitchener1, proxy: v-317-VM
2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10] dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP: 10.91.0.237].



Regards,
Antoine Boucher


Re: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

Posted by Antoine Boucher <an...@haltondc.com>.
Hi Wei,

Thank you for your information.  It turns out that the host was not properly updated to 4.17.2

All work now.

Thanks again!


Regards,
Antoine


> On Feb 22, 2023, at 7:51 AM, Wei ZHOU <us...@gmail.com> wrote:
> 
> The scripts are transferred from kvm host via scp command. It would be good
> to check
> - kvm host has cloudstack-agent installed and upgraded
> - scp to ssvm/router vms via cloud0 is allowed on kvm host
> 
> -Wei
> 
> 
> 
> On Wednesday, 22 February 2023, Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com>>
> wrote:
> 
>> Is there any reason why the /usr/local/cloud/systemvm directory would be
>> missing from the SSVM one one zone but not on an other?
>> 
>> Is the directory added during the systemvm creation or is it part of the
>> base system VM template?
>> 
>> Both /etc/cloudstack-release show: Cloudstack Release 4.17.2 Fri 09 Dec
>> 2022 12:51:18 PM UTC
>> 
>> Regards,
>> Antoine
>> 
>> 
>> 
>>> On Feb 21, 2023, at 3:31 PM, Antoine Boucher <an...@haltondc.com>
>> wrote:
>>> 
>>> I compared the system template fro KVM of both zone and they seem
>> identical.
>>> 
>>> 
>>> The /usr/local/cloud/systemvm/ directory exist on SSVM on zone 1 exist
>> but the /usr/local/cloud/ directory of the zone 2 SSVM does not exist?
>>> 
>>> 
>>> 
>>> Antoine Boucher
>>> AntoineB@haltondc.com
>>> [o] +1-226-505-9734
>>> www.haltondc.com
>>> 
>>> “Data security made simple”
>>> 
>>> 
>>> <HDClogo7-small.png>
>>> 
>>> 
>>> Confidentiality Warning: This message and any attachments are intended
>> only for the use of the intended recipient(s), are confidential, and may be
>> privileged. If you are not the intended recipient, you are hereby notified
>> that any review, retransmission, conversion to hard copy, copying,
>> circulation or other use of this message and any attachments is strictly
>> prohibited. If you are not the intended recipient, please notify the sender
>> immediately by return e-mail, and delete this message and any attachments
>> from your system.
>>> 
>>> 
>>>> On Feb 21, 2023, at 1:31 PM, Antoine Boucher <an...@haltondc.com>
>> wrote:
>>>> 
>>>> 4.17.2
>>>> 
>>>> Antoine Boucher
>>>> AntoineB@haltondc.com
>>>> [o] +1-226-505-9734
>>>> www.haltondc.com
>>>> 
>>>> “Data security made simple and affordable”
>>>> 
>>>> 
>>>> On Feb 21, 2023, at 11:51, Wei ZHOU <us...@gmail.com> wrote:
>>>> 
>>>> can you check the /etc/cloudstack-release in ssvm ?
>>>> 
>>>> -Wei
>>>> 
>>>> On Tuesday, 21 February 2023, Antoine Boucher <antoineb@haltondc.com
>> <ma...@haltondc.com>> wrote:
>>>>> Here are the logs from daemon.log of the failing SSVM
>>>>> 
>>>>> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed to
>> locate executable /usr/local/cloud/systemvm/_run.sh: No such file or
>> directory
>>>>> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed at step
>> EXEC spawning /usr/local/cloud/systemvm/_run.sh: No such file or directory
>>>>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Main process
>> exited, code=exited, status=203/EXEC
>>>>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Failed with result
>> 'exit-code'.
>>>>> Feb 21 02:36:16 systemvm systemd[1]: systemd-update-utmp-runlevel.service:
>> Succeeded.
>>>>> Feb 21 02:36:16 systemvm systemd[1]: Finished Update UTMP about System
>> Runlevel Changes.
>>>>> Feb 21 02:36:16 systemvm systemd[1]: Startup finished in 2.285s
>> (kernel) + 2min 16.468s (userspace) = 2min 18.754s.
>>>>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Scheduled restart
>> job, restart counter is at 1.
>>>>> Feb 21 02:36:16 systemvm systemd[1]: Stopped CloudStack Agent service.
>>>>> 
>>>>> This repeats 5 times and fails
>>>>> 
>>>>> The /usr/local/cloud/systemvm/ directory does not exist on the SSVM.
>>>>> 
>>>>> 
>>>>> 
>>>>> 
>>>>> Antoine Boucher
>>>>> AntoineB@haltondc.com <ma...@haltondc.com> <ma...@haltondc.com>
>>>>> [o] +1-226-505-9734
>>>>> www.haltondc.com <http://www.haltondc.com/> <http://www.haltondc.com/>
>>>>> 
>>>>> “Data security made simple”
>>>>> 
>>>>> 
>>>>> <HDClogo7-small.png>
>>>>> 
>>>>> 
>>>>> Confidentiality Warning: This message and any attachments are intended
>> only for the use of the intended recipient(s), are confidential, and may be
>> privileged. If you are not the intended recipient, you are hereby notified
>> that any review, retransmission, conversion to hard copy, copying,
>> circulation or other use of this message and any attachments is strictly
>> prohibited. If you are not the intended recipient, please notify the sender
>> immediately by return e-mail, and delete this message and any attachments
>> from your system.
>>>>> 
>>>>> 
>>>>>> On Feb 21, 2023, at 7:53 AM, Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com>
>> <ma...@haltondc.com>> wrote:
>>>>>> 
>>>>>> They are not old they are the new ones.  I have deleted them a number
>> of times after the upgrade but the issue prevails.
>>>>>> 
>>>>>> Antoine Boucher
>>>>>> AntoineB@haltondc.com <ma...@haltondc.com> <ma...@haltondc.com>
>>>>>> [o] +1-226-505-9734
>>>>>> www.haltondc.com <http://www.haltondc.com/> <http://www.haltondc.com/>
>>>>>> 
>>>>>> “Data security made simple and affordable”
>>>>>> 
>>>>>> 
>>>>>> On Feb 21, 2023, at 00:24, Rohit Yadav <rohit.yadav@shapeblue.com <ma...@shapeblue.com>
>> <ma...@shapeblue.com>> wrote:
>>>>>> 
>>>>>> 
>>>>>> You can destroy these old systemvms or do a stop and start on them.
>>>>>> 
>>>>>> Regards.
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> From: Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com> <mailto:
>> antoineb@haltondc.com <ma...@haltondc.com>>>
>>>>>> Sent: Tuesday, February 21, 2023 10:40:46 AM
>>>>>> To: users <users@cloudstack.apache.org <ma...@cloudstack.apache.org> <mailto:users@cloudstack.
>> apache.org <http://apache.org/>>>
>>>>>> Subject: Failed to setup certificates for system vm error on 2nd Zone
>> after upgrading to 4.17.2
>>>>>> 
>>>>>> After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM
>> (and VRs) of the first zone upgraded without issues but the system VMs
>> (s-318-VM and v-317-VM) of the second zone (Kitchener1) are no longer able
>> to establish connection with the management server.  I have rebooted the
>> host they are on, deleted the system vm to be recreated, I also logged into
>> the two system VM and found nothing so far except fo the following
>> management server logs:
>>>>>> 
>>>>>> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
>> (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
>>>>>> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
>> (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
>>>>>> 
>>>>>> The host of these 2 system VM was missed in the original update, such
>> that is was updated after the Management Server was running with 4.17.2
>> instead of before.
>>>>>> 
>>>>>> Would anyone have suggestion to resolve the issue?
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> 2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
>> (logid:352477d9) Seq 44-1267200345151373322: Received:  { Ans: , MgmtId:
>> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer,
>> CheckSshAnswer } }
>>>>>> 2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
>> (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid:
>> "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state
>> transited from [Starting] to [Running] with event [OperationSucceeded].
>> VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid":
>> "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host
>> {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf",
>> "type"="Routing"}, host before state transition: Host {"id": "44", "name":
>> "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf",
>> "type"="Routing"}
>>>>>> 2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request]
>> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
>> (logid:5d1ede3b) Seq 44-1267200345151373326: Sending  { Cmd , MgmtId:
>> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"
>> org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/> <http://org.apache.cloudstack.ca/
>>> .SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"
>> router.name <http://router.name/>":"s-318-VM","Control":"169.254.254.63"
>> ,"Storage":"10.91.6.249","Public":"64.32.40.68","
>> Management":"10.91.0.244","router.ip":"169.254.254.63"},"wait":"60","
>> bypassHostMaintenance":"false"}}] }
>>>>>> 2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
>> (logid:352477d9) Start completed for VM VM instance {id: "317", name:
>> "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a",
>> type="ConsoleProxy"}
>>>>>> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request]
>> (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326:
>> Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"
>> org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/> <http://org.apache.cloudstack.ca/
>>> .SetupCertificateAnswer":{"result":"false","wait":"0","
>> bypassHostMaintenance":"false"}}] }
>>>>>> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request]
>> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
>> (logid:5d1ede3b) Seq 44-1267200345151373326: Received:  { Ans: , MgmtId:
>> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, {
>> SetupCertificateAnswer } }
>>>>>> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
>> (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
>>>>>> 2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy]
>> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
>> (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"
>> dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"
>> VirtualMachineManagerImpl"}
>>>>>> 2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher]
>> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b)
>> Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job
>> origin: 20367
>>>>>> 2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
>> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b)
>> Remove job-20401 from job monitoring
>>>>>> 2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
>> (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm
>> alert
>>>>>> 2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
>> (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up,
>> zone: Kitchener1, secStorageVm: s-318-VM, public
>>>>>> 2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl]
>> (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19]
>> dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm
>> up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68,
>> private IP: 10.91.0.244].
>>>>>> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl]
>> (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance
>> {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87",
>> type="SecondaryStorageVm"} was started.
>>>>>> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl]
>> (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is
>> not even started, wait until next turn
>>>>>> 2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
>> (logid:352477d9) Seq 44-1267200345151373327: Sending  { Cmd , MgmtId:
>> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"
>> org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/> <http://org.apache.cloudstack.ca/
>>> .SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"
>> router.name <http://router.name/>":"v-317-VM","Control":"169.254.21.136"
>> ,"Public":"64.32.40.66","Management":"10.91.0.237","
>> router.ip":"169.254.21.136"},"wait":"60","bypassHostMaintenance":"false"}}]
>> }
>>>>>> 2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache]
>> (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978:
>> Executing request
>>>>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache]
>> (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978:
>> Response Received:
>>>>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
>> (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId:
>> 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
>> } }
>>>>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl]
>> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
>> class com.cloud.agent.api.GetVolumeStatsCommand:
>>>>>> 2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache]
>> (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682:
>> Executing request
>>>>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache]
>> (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682:
>> Response Received:
>>>>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
>> (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId:
>> 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
>> } }
>>>>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl]
>> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
>> class com.cloud.agent.api.GetVolumeStatsCommand:
>>>>>> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request]
>> (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327:
>> Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"
>> org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/> <http://org.apache.cloudstack.ca/
>>> .SetupCertificateAnswer":{"result":"false","wait":"0","
>> bypassHostMaintenance":"false"}}] }
>>>>>> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
>> (logid:352477d9) Seq 44-1267200345151373327: Received:  { Ans: , MgmtId:
>> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, {
>> SetupCertificateAnswer } }
>>>>>> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
>> (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
>>>>>> 2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
>> (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"
>> dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"
>> VirtualMachineManagerImpl"}
>>>>>> 2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
>> (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId:
>> 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
>> } }
>>>>>> 2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl]
>> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
>> class com.cloud.agent.api.GetVolumeStatsCommand:
>>>>>> 2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9)
>> Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job
>> origin: 20366
>>>>>> 2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
>> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9)
>> Remove job-20400 from job monitoring
>>>>>> 2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl]
>> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is
>> started
>>>>>> 2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl]
>> (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq
>> 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11,
>> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand"
>> :{"_proxyVmId":"290","_loadInfo":"{
>>>>>>  "connections": []
>>>>>> }","wait":"0","bypassHostMaintenance":"false"}}] }
>>>>>> 2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
>> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
>>>>>> 2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
>> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone:
>> Kitchener1, proxy: v-317-VM
>>>>>> 2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl]
>> (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq
>> 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010,
>> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","
>> bypassHostMaintenance":"false"}}] }
>>>>>> 2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl]
>> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10]
>> dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in
>> zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP:
>> 10.91.0.237].
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> Regards,
>>>>>> Antoine Boucher


Re: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

Posted by Wei ZHOU <us...@gmail.com>.
The scripts are transferred from kvm host via scp command. It would be good
to check
- kvm host has cloudstack-agent installed and upgraded
- scp to ssvm/router vms via cloud0 is allowed on kvm host

-Wei



On Wednesday, 22 February 2023, Antoine Boucher <an...@haltondc.com>
wrote:

> Is there any reason why the /usr/local/cloud/systemvm directory would be
> missing from the SSVM one one zone but not on an other?
>
> Is the directory added during the systemvm creation or is it part of the
> base system VM template?
>
> Both /etc/cloudstack-release show: Cloudstack Release 4.17.2 Fri 09 Dec
> 2022 12:51:18 PM UTC
>
> Regards,
> Antoine
>
>
>
> > On Feb 21, 2023, at 3:31 PM, Antoine Boucher <an...@haltondc.com>
> wrote:
> >
> > I compared the system template fro KVM of both zone and they seem
> identical.
> >
> >
> > The /usr/local/cloud/systemvm/ directory exist on SSVM on zone 1 exist
> but the /usr/local/cloud/ directory of the zone 2 SSVM does not exist?
> >
> >
> >
> > Antoine Boucher
> > AntoineB@haltondc.com
> > [o] +1-226-505-9734
> > www.haltondc.com
> >
> > “Data security made simple”
> >
> >
> > <HDClogo7-small.png>
> >
> >
> > Confidentiality Warning: This message and any attachments are intended
> only for the use of the intended recipient(s), are confidential, and may be
> privileged. If you are not the intended recipient, you are hereby notified
> that any review, retransmission, conversion to hard copy, copying,
> circulation or other use of this message and any attachments is strictly
> prohibited. If you are not the intended recipient, please notify the sender
> immediately by return e-mail, and delete this message and any attachments
> from your system.
> >
> >
> >> On Feb 21, 2023, at 1:31 PM, Antoine Boucher <an...@haltondc.com>
> wrote:
> >>
> >> 4.17.2
> >>
> >> Antoine Boucher
> >> AntoineB@haltondc.com
> >> [o] +1-226-505-9734
> >> www.haltondc.com
> >>
> >> “Data security made simple and affordable”
> >>
> >>
> >> On Feb 21, 2023, at 11:51, Wei ZHOU <us...@gmail.com> wrote:
> >>
> >> can you check the /etc/cloudstack-release in ssvm ?
> >>
> >> -Wei
> >>
> >> On Tuesday, 21 February 2023, Antoine Boucher <antoineb@haltondc.com
> <ma...@haltondc.com>> wrote:
> >>> Here are the logs from daemon.log of the failing SSVM
> >>>
> >>> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed to
> locate executable /usr/local/cloud/systemvm/_run.sh: No such file or
> directory
> >>> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed at step
> EXEC spawning /usr/local/cloud/systemvm/_run.sh: No such file or directory
> >>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Main process
> exited, code=exited, status=203/EXEC
> >>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Failed with result
> 'exit-code'.
> >>> Feb 21 02:36:16 systemvm systemd[1]: systemd-update-utmp-runlevel.service:
> Succeeded.
> >>> Feb 21 02:36:16 systemvm systemd[1]: Finished Update UTMP about System
> Runlevel Changes.
> >>> Feb 21 02:36:16 systemvm systemd[1]: Startup finished in 2.285s
> (kernel) + 2min 16.468s (userspace) = 2min 18.754s.
> >>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Scheduled restart
> job, restart counter is at 1.
> >>> Feb 21 02:36:16 systemvm systemd[1]: Stopped CloudStack Agent service.
> >>>
> >>> This repeats 5 times and fails
> >>>
> >>> The /usr/local/cloud/systemvm/ directory does not exist on the SSVM.
> >>>
> >>>
> >>>
> >>>
> >>> Antoine Boucher
> >>> AntoineB@haltondc.com <ma...@haltondc.com>
> >>> [o] +1-226-505-9734
> >>> www.haltondc.com <http://www.haltondc.com/>
> >>>
> >>> “Data security made simple”
> >>>
> >>>
> >>> <HDClogo7-small.png>
> >>>
> >>>
> >>> Confidentiality Warning: This message and any attachments are intended
> only for the use of the intended recipient(s), are confidential, and may be
> privileged. If you are not the intended recipient, you are hereby notified
> that any review, retransmission, conversion to hard copy, copying,
> circulation or other use of this message and any attachments is strictly
> prohibited. If you are not the intended recipient, please notify the sender
> immediately by return e-mail, and delete this message and any attachments
> from your system.
> >>>
> >>>
> >>>> On Feb 21, 2023, at 7:53 AM, Antoine Boucher <antoineb@haltondc.com
> <ma...@haltondc.com>> wrote:
> >>>>
> >>>> They are not old they are the new ones.  I have deleted them a number
> of times after the upgrade but the issue prevails.
> >>>>
> >>>> Antoine Boucher
> >>>> AntoineB@haltondc.com <ma...@haltondc.com>
> >>>> [o] +1-226-505-9734
> >>>> www.haltondc.com <http://www.haltondc.com/>
> >>>>
> >>>> “Data security made simple and affordable”
> >>>>
> >>>>
> >>>> On Feb 21, 2023, at 00:24, Rohit Yadav <rohit.yadav@shapeblue.com
> <ma...@shapeblue.com>> wrote:
> >>>>
> >>>> 
> >>>> You can destroy these old systemvms or do a stop and start on them.
> >>>>
> >>>> Regards.
> >>>>
> >>>>
> >>>>
> >>>>
> >>>> From: Antoine Boucher <antoineb@haltondc.com <mailto:
> antoineb@haltondc.com>>
> >>>> Sent: Tuesday, February 21, 2023 10:40:46 AM
> >>>> To: users <users@cloudstack.apache.org <mailto:users@cloudstack.
> apache.org>>
> >>>> Subject: Failed to setup certificates for system vm error on 2nd Zone
> after upgrading to 4.17.2
> >>>>
> >>>> After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM
> (and VRs) of the first zone upgraded without issues but the system VMs
> (s-318-VM and v-317-VM) of the second zone (Kitchener1) are no longer able
> to establish connection with the management server.  I have rebooted the
> host they are on, deleted the system vm to be recreated, I also logged into
> the two system VM and found nothing so far except fo the following
> management server logs:
> >>>>
> >>>> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
> (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
> >>>> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
> >>>>
> >>>> The host of these 2 system VM was missed in the original update, such
> that is was updated after the Management Server was running with 4.17.2
> instead of before.
> >>>>
> >>>> Would anyone have suggestion to resolve the issue?
> >>>>
> >>>>
> >>>>
> >>>>
> >>>>
> >>>> 2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Seq 44-1267200345151373322: Received:  { Ans: , MgmtId:
> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer,
> CheckSshAnswer } }
> >>>> 2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid:
> "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state
> transited from [Starting] to [Running] with event [OperationSucceeded].
> VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid":
> "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host
> {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf",
> "type"="Routing"}, host before state transition: Host {"id": "44", "name":
> "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf",
> "type"="Routing"}
> >>>> 2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
> (logid:5d1ede3b) Seq 44-1267200345151373326: Sending  { Cmd , MgmtId:
> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"
> org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/
> >.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"
> router.name <http://router.name/>":"s-318-VM","Control":"169.254.254.63"
> ,"Storage":"10.91.6.249","Public":"64.32.40.68","
> Management":"10.91.0.244","router.ip":"169.254.254.63"},"wait":"60","
> bypassHostMaintenance":"false"}}] }
> >>>> 2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Start completed for VM VM instance {id: "317", name:
> "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a",
> type="ConsoleProxy"}
> >>>> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326:
> Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"
> org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/
> >.SetupCertificateAnswer":{"result":"false","wait":"0","
> bypassHostMaintenance":"false"}}] }
> >>>> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
> (logid:5d1ede3b) Seq 44-1267200345151373326: Received:  { Ans: , MgmtId:
> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, {
> SetupCertificateAnswer } }
> >>>> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
> (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
> >>>> 2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
> (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"
> dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"
> VirtualMachineManagerImpl"}
> >>>> 2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b)
> Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job
> origin: 20367
> >>>> 2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b)
> Remove job-20401 from job monitoring
> >>>> 2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
> (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm
> alert
> >>>> 2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
> (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up,
> zone: Kitchener1, secStorageVm: s-318-VM, public
> >>>> 2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl]
> (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19]
> dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm
> up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68,
> private IP: 10.91.0.244].
> >>>> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance
> {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87",
> type="SecondaryStorageVm"} was started.
> >>>> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl]
> (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is
> not even started, wait until next turn
> >>>> 2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Seq 44-1267200345151373327: Sending  { Cmd , MgmtId:
> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"
> org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/
> >.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"
> router.name <http://router.name/>":"v-317-VM","Control":"169.254.21.136"
> ,"Public":"64.32.40.66","Management":"10.91.0.237","
> router.ip":"169.254.21.136"},"wait":"60","bypassHostMaintenance":"false"}}]
> }
> >>>> 2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978:
> Executing request
> >>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978:
> Response Received:
> >>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
> (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId:
> 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
> } }
> >>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl]
> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
> class com.cloud.agent.api.GetVolumeStatsCommand:
> >>>> 2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682:
> Executing request
> >>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682:
> Response Received:
> >>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
> (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId:
> 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
> } }
> >>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl]
> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
> class com.cloud.agent.api.GetVolumeStatsCommand:
> >>>> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327:
> Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"
> org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/
> >.SetupCertificateAnswer":{"result":"false","wait":"0","
> bypassHostMaintenance":"false"}}] }
> >>>> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Seq 44-1267200345151373327: Received:  { Ans: , MgmtId:
> 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, {
> SetupCertificateAnswer } }
> >>>> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
> >>>> 2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"
> dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"
> VirtualMachineManagerImpl"}
> >>>> 2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
> (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId:
> 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
> } }
> >>>> 2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl]
> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
> class com.cloud.agent.api.GetVolumeStatsCommand:
> >>>> 2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9)
> Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job
> origin: 20366
> >>>> 2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9)
> Remove job-20400 from job monitoring
> >>>> 2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is
> started
> >>>> 2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq
> 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand"
> :{"_proxyVmId":"290","_loadInfo":"{
> >>>>   "connections": []
> >>>> }","wait":"0","bypassHostMaintenance":"false"}}] }
> >>>> 2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
> >>>> 2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone:
> Kitchener1, proxy: v-317-VM
> >>>> 2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq
> 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","
> bypassHostMaintenance":"false"}}] }
> >>>> 2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl]
> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10]
> dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in
> zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP:
> 10.91.0.237].
> >>>>
> >>>>
> >>>>
> >>>> Regards,
> >>>> Antoine Boucher
> >>>>
> >>>
> >
>
>

Re: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

Posted by Antoine Boucher <an...@haltondc.com>.
Is there any reason why the /usr/local/cloud/systemvm directory would be missing from the SSVM one one zone but not on an other?

Is the directory added during the systemvm creation or is it part of the base system VM template?

Both /etc/cloudstack-release show: Cloudstack Release 4.17.2 Fri 09 Dec 2022 12:51:18 PM UTC

Regards,
Antoine



> On Feb 21, 2023, at 3:31 PM, Antoine Boucher <an...@haltondc.com> wrote:
> 
> I compared the system template fro KVM of both zone and they seem identical.  
> 
> 
> The /usr/local/cloud/systemvm/ directory exist on SSVM on zone 1 exist but the /usr/local/cloud/ directory of the zone 2 SSVM does not exist?
> 
> 
> 
> Antoine Boucher
> AntoineB@haltondc.com
> [o] +1-226-505-9734
> www.haltondc.com
> 
> “Data security made simple”
> 
> 
> <HDClogo7-small.png>
> 
> 
> Confidentiality Warning: This message and any attachments are intended only for the use of the intended recipient(s), are confidential, and may be privileged. If you are not the intended recipient, you are hereby notified that any review, retransmission, conversion to hard copy, copying, circulation or other use of this message and any attachments is strictly prohibited. If you are not the intended recipient, please notify the sender immediately by return e-mail, and delete this message and any attachments from your system.
> 
> 
>> On Feb 21, 2023, at 1:31 PM, Antoine Boucher <an...@haltondc.com> wrote:
>> 
>> 4.17.2
>> 
>> Antoine Boucher
>> AntoineB@haltondc.com
>> [o] +1-226-505-9734
>> www.haltondc.com
>> 
>> “Data security made simple and affordable”
>> 
>> 
>> On Feb 21, 2023, at 11:51, Wei ZHOU <us...@gmail.com> wrote:
>> 
>> can you check the /etc/cloudstack-release in ssvm ?
>> 
>> -Wei
>> 
>> On Tuesday, 21 February 2023, Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com>> wrote:
>>> Here are the logs from daemon.log of the failing SSVM
>>> 
>>> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed to locate executable /usr/local/cloud/systemvm/_run.sh: No such file or directory
>>> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed at step EXEC spawning /usr/local/cloud/systemvm/_run.sh: No such file or directory
>>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Main process exited, code=exited, status=203/EXEC
>>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Failed with result 'exit-code'.
>>> Feb 21 02:36:16 systemvm systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
>>> Feb 21 02:36:16 systemvm systemd[1]: Finished Update UTMP about System Runlevel Changes.
>>> Feb 21 02:36:16 systemvm systemd[1]: Startup finished in 2.285s (kernel) + 2min 16.468s (userspace) = 2min 18.754s.
>>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Scheduled restart job, restart counter is at 1.
>>> Feb 21 02:36:16 systemvm systemd[1]: Stopped CloudStack Agent service.
>>> 
>>> This repeats 5 times and fails
>>> 
>>> The /usr/local/cloud/systemvm/ directory does not exist on the SSVM.  
>>> 
>>> 
>>> 
>>> 
>>> Antoine Boucher
>>> AntoineB@haltondc.com <ma...@haltondc.com>
>>> [o] +1-226-505-9734
>>> www.haltondc.com <http://www.haltondc.com/>
>>> 
>>> “Data security made simple”
>>> 
>>> 
>>> <HDClogo7-small.png>
>>> 
>>> 
>>> Confidentiality Warning: This message and any attachments are intended only for the use of the intended recipient(s), are confidential, and may be privileged. If you are not the intended recipient, you are hereby notified that any review, retransmission, conversion to hard copy, copying, circulation or other use of this message and any attachments is strictly prohibited. If you are not the intended recipient, please notify the sender immediately by return e-mail, and delete this message and any attachments from your system.
>>> 
>>> 
>>>> On Feb 21, 2023, at 7:53 AM, Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com>> wrote:
>>>> 
>>>> They are not old they are the new ones.  I have deleted them a number of times after the upgrade but the issue prevails.  
>>>> 
>>>> Antoine Boucher
>>>> AntoineB@haltondc.com <ma...@haltondc.com>
>>>> [o] +1-226-505-9734
>>>> www.haltondc.com <http://www.haltondc.com/>
>>>> 
>>>> “Data security made simple and affordable”
>>>> 
>>>> 
>>>> On Feb 21, 2023, at 00:24, Rohit Yadav <rohit.yadav@shapeblue.com <ma...@shapeblue.com>> wrote:
>>>> 
>>>> 
>>>> You can destroy these old systemvms or do a stop and start on them. 
>>>> 
>>>> Regards.
>>>> 
>>>>   
>>>> 
>>>>   
>>>> From: Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com>>
>>>> Sent: Tuesday, February 21, 2023 10:40:46 AM
>>>> To: users <users@cloudstack.apache.org <ma...@cloudstack.apache.org>>
>>>> Subject: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2
>>>>  
>>>> After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM (and VRs) of the first zone upgraded without issues but the system VMs (s-318-VM and v-317-VM) of the second zone (Kitchener1) are no longer able to establish connection with the management server.  I have rebooted the host they are on, deleted the system vm to be recreated, I also logged into the two system VM and found nothing so far except fo the following management server logs:
>>>> 
>>>> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM 
>>>> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
>>>> 
>>>> The host of these 2 system VM was missed in the original update, such that is was updated after the Management Server was running with 4.17.2 instead of before.
>>>> 
>>>> Would anyone have suggestion to resolve the issue?
>>>> 
>>>> 
>>>> 
>>>> 
>>>> 
>>>> 2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373322: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer } }
>>>> 2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state transited from [Starting] to [Running] with event [OperationSucceeded]. VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, host before state transition: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}
>>>> 2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/>.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name <http://router.name/>":"s-318-VM","Control":"169.254.254.63","Storage":"10.91.6.249","Public":"64.32.40.68","Management":"10.91.0.244","router.ip":"169.254.254.63"},"wait":"60","bypassHostMaintenance":"false"}}] }
>>>> 2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Start completed for VM VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"}
>>>> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/>.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
>>>> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
>>>> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
>>>> 2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"VirtualMachineManagerImpl"}
>>>> 2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job origin: 20367
>>>> 2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Remove job-20401 from job monitoring
>>>> 2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm alert
>>>> 2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up, zone: Kitchener1, secStorageVm: s-318-VM, public 
>>>> 2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19] dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68, private IP: 10.91.0.244].
>>>> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87", type="SecondaryStorageVm"} was started.
>>>> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is not even started, wait until next turn
>>>> 2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/>.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name <http://router.name/>":"v-317-VM","Control":"169.254.21.136","Public":"64.32.40.66","Management":"10.91.0.237","router.ip":"169.254.21.136"},"wait":"60","bypassHostMaintenance":"false"}}] }
>>>> 2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978: Executing request
>>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978: Response Received: 
>>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId: 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
>>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
>>>> 2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682: Executing request
>>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682: Response Received: 
>>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId: 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
>>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
>>>> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/>.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
>>>> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
>>>> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
>>>> 2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"VirtualMachineManagerImpl"}
>>>> 2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId: 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
>>>> 2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
>>>> 2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job origin: 20366
>>>> 2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Remove job-20400 from job monitoring
>>>> 2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is started
>>>> 2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"290","_loadInfo":"{
>>>>   "connections": []
>>>> }","wait":"0","bypassHostMaintenance":"false"}}] }
>>>> 2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
>>>> 2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone: Kitchener1, proxy: v-317-VM
>>>> 2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
>>>> 2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10] dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP: 10.91.0.237].
>>>> 
>>>> 
>>>> 
>>>> Regards,
>>>> Antoine Boucher
>>>> 
>>> 
> 


Re: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

Posted by Antoine Boucher <an...@haltondc.com>.
I compared the system template fro KVM of both zone and they seem identical.  


The /usr/local/cloud/systemvm/ directory exist on SSVM on zone 1 exist but the /usr/local/cloud/ directory of the zone 2 SSVM does not exist?



Antoine Boucher
AntoineB@haltondc.com
[o] +1-226-505-9734
www.haltondc.com

“Data security made simple”





Confidentiality Warning: This message and any attachments are intended only for the use of the intended recipient(s), are confidential, and may be privileged. If you are not the intended recipient, you are hereby notified that any review, retransmission, conversion to hard copy, copying, circulation or other use of this message and any attachments is strictly prohibited. If you are not the intended recipient, please notify the sender immediately by return e-mail, and delete this message and any attachments from your system.


> On Feb 21, 2023, at 1:31 PM, Antoine Boucher <an...@haltondc.com> wrote:
> 
> 4.17.2
> 
> Antoine Boucher
> AntoineB@haltondc.com
> [o] +1-226-505-9734
> www.haltondc.com
> 
> “Data security made simple and affordable”
> 
> 
> On Feb 21, 2023, at 11:51, Wei ZHOU <us...@gmail.com> wrote:
> 
> can you check the /etc/cloudstack-release in ssvm ?
> 
> -Wei
> 
> On Tuesday, 21 February 2023, Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com>> wrote:
>> Here are the logs from daemon.log of the failing SSVM
>> 
>> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed to locate executable /usr/local/cloud/systemvm/_run.sh: No such file or directory
>> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed at step EXEC spawning /usr/local/cloud/systemvm/_run.sh: No such file or directory
>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Main process exited, code=exited, status=203/EXEC
>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Failed with result 'exit-code'.
>> Feb 21 02:36:16 systemvm systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
>> Feb 21 02:36:16 systemvm systemd[1]: Finished Update UTMP about System Runlevel Changes.
>> Feb 21 02:36:16 systemvm systemd[1]: Startup finished in 2.285s (kernel) + 2min 16.468s (userspace) = 2min 18.754s.
>> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Scheduled restart job, restart counter is at 1.
>> Feb 21 02:36:16 systemvm systemd[1]: Stopped CloudStack Agent service.
>> 
>> This repeats 5 times and fails
>> 
>> The /usr/local/cloud/systemvm/ directory does not exist on the SSVM.  
>> 
>> 
>> 
>> 
>> Antoine Boucher
>> AntoineB@haltondc.com <ma...@haltondc.com>
>> [o] +1-226-505-9734
>> www.haltondc.com <http://www.haltondc.com/>
>> 
>> “Data security made simple”
>> 
>> 
>> 
>> 
>> 
>> Confidentiality Warning: This message and any attachments are intended only for the use of the intended recipient(s), are confidential, and may be privileged. If you are not the intended recipient, you are hereby notified that any review, retransmission, conversion to hard copy, copying, circulation or other use of this message and any attachments is strictly prohibited. If you are not the intended recipient, please notify the sender immediately by return e-mail, and delete this message and any attachments from your system.
>> 
>> 
>>> On Feb 21, 2023, at 7:53 AM, Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com>> wrote:
>>> 
>>> They are not old they are the new ones.  I have deleted them a number of times after the upgrade but the issue prevails.  
>>> 
>>> Antoine Boucher
>>> AntoineB@haltondc.com <ma...@haltondc.com>
>>> [o] +1-226-505-9734
>>> www.haltondc.com <http://www.haltondc.com/>
>>> 
>>> “Data security made simple and affordable”
>>> 
>>> 
>>> On Feb 21, 2023, at 00:24, Rohit Yadav <rohit.yadav@shapeblue.com <ma...@shapeblue.com>> wrote:
>>> 
>>> 
>>> You can destroy these old systemvms or do a stop and start on them. 
>>> 
>>> Regards.
>>> 
>>>   
>>> 
>>>   
>>> From: Antoine Boucher <antoineb@haltondc.com <ma...@haltondc.com>>
>>> Sent: Tuesday, February 21, 2023 10:40:46 AM
>>> To: users <users@cloudstack.apache.org <ma...@cloudstack.apache.org>>
>>> Subject: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2
>>>  
>>> After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM (and VRs) of the first zone upgraded without issues but the system VMs (s-318-VM and v-317-VM) of the second zone (Kitchener1) are no longer able to establish connection with the management server.  I have rebooted the host they are on, deleted the system vm to be recreated, I also logged into the two system VM and found nothing so far except fo the following management server logs:
>>> 
>>> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM 
>>> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
>>> 
>>> The host of these 2 system VM was missed in the original update, such that is was updated after the Management Server was running with 4.17.2 instead of before.
>>> 
>>> Would anyone have suggestion to resolve the issue?
>>> 
>>> 
>>> 
>>> 
>>> 
>>> 2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373322: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer } }
>>> 2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state transited from [Starting] to [Running] with event [OperationSucceeded]. VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, host before state transition: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}
>>> 2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/>.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name <http://router.name/>":"s-318-VM","Control":"169.254.254.63","Storage":"10.91.6.249","Public":"64.32.40.68","Management":"10.91.0.244","router.ip":"169.254.254.63"},"wait":"60","bypassHostMaintenance":"false"}}] }
>>> 2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Start completed for VM VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"}
>>> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/>.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
>>> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
>>> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
>>> 2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"VirtualMachineManagerImpl"}
>>> 2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job origin: 20367
>>> 2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Remove job-20401 from job monitoring
>>> 2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm alert
>>> 2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up, zone: Kitchener1, secStorageVm: s-318-VM, public 
>>> 2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19] dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68, private IP: 10.91.0.244].
>>> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87", type="SecondaryStorageVm"} was started.
>>> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is not even started, wait until next turn
>>> 2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/>.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name <http://router.name/>":"v-317-VM","Control":"169.254.21.136","Public":"64.32.40.66","Management":"10.91.0.237","router.ip":"169.254.21.136"},"wait":"60","bypassHostMaintenance":"false"}}] }
>>> 2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978: Executing request
>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978: Response Received: 
>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId: 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
>>> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
>>> 2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682: Executing request
>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682: Response Received: 
>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId: 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
>>> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
>>> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca <http://org.apache.cloudstack.ca/>.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
>>> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
>>> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
>>> 2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"VirtualMachineManagerImpl"}
>>> 2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId: 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
>>> 2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
>>> 2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job origin: 20366
>>> 2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Remove job-20400 from job monitoring
>>> 2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is started
>>> 2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"290","_loadInfo":"{
>>>   "connections": []
>>> }","wait":"0","bypassHostMaintenance":"false"}}] }
>>> 2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
>>> 2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone: Kitchener1, proxy: v-317-VM
>>> 2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
>>> 2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10] dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP: 10.91.0.237].
>>> 
>>> 
>>> 
>>> Regards,
>>> Antoine Boucher
>>> 
>> 


Re: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

Posted by Wei ZHOU <us...@gmail.com>.
can you check the /etc/cloudstack-release in ssvm ?

-Wei

On Tuesday, 21 February 2023, Antoine Boucher <an...@haltondc.com> wrote:

> Here are the logs from daemon.log of the failing SSVM
>
> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed to locate
> executable /usr/local/cloud/systemvm/_run.sh: No such file or directory
>
> Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed at step EXEC
> spawning /usr/local/cloud/systemvm/_run.sh: No such file or directory
>
> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Main process exited,
> code=exited, status=203/EXEC
>
> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Failed with result
> 'exit-code'.
>
> Feb 21 02:36:16 systemvm systemd[1]: systemd-update-utmp-runlevel.service:
> Succeeded.
>
> Feb 21 02:36:16 systemvm systemd[1]: Finished Update UTMP about System
> Runlevel Changes.
>
> Feb 21 02:36:16 systemvm systemd[1]: Startup finished in 2.285s (kernel) +
> 2min 16.468s (userspace) = 2min 18.754s.
>
> Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Scheduled restart job,
> restart counter is at 1.
>
> Feb 21 02:36:16 systemvm systemd[1]: Stopped CloudStack Agent service.
>
> This repeats 5 times and fails
>
> The /usr/local/cloud/systemvm/ directory does not exist on the SSVM.
>
>
>
>
> *Antoine Boucher*
> AntoineB@haltondc.com
> [o] +1-226-505-9734
> www.haltondc.com
>
> “Data security made simple”
>
>
> [image: HDClogo7-small.png]
>
>
> Confidentiality Warning: This message and any attachments are intended
> only for the use of the intended recipient(s), are confidential, and may be
> privileged. If you are not the intended recipient, you are hereby notified
> that any review, retransmission, conversion to hard copy,
> copying, circulation or other use of this message and any attachments is
> strictly prohibited. If you are not the intended recipient, please notify
> the sender immediately by return e-mail, and delete this message and any
> attachments from your system.
>
>
> On Feb 21, 2023, at 7:53 AM, Antoine Boucher <an...@haltondc.com>
> wrote:
>
> They are not old they are the new ones.  I have deleted them a number of
> times after the upgrade but the issue prevails.
>
> Antoine Boucher
> AntoineB@haltondc.com
> [o] +1-226-505-9734
> www.haltondc.com
>
> “Data security made simple and affordable”
>
>
> On Feb 21, 2023, at 00:24, Rohit Yadav <ro...@shapeblue.com> wrote:
>
> 
> You can destroy these old systemvms or do a stop and start on them.
>
> Regards.
>
>
>
>
> ------------------------------
> *From:* Antoine Boucher <an...@haltondc.com>
> *Sent:* Tuesday, February 21, 2023 10:40:46 AM
> *To:* users <us...@cloudstack.apache.org>
> *Subject:* Failed to setup certificates for system vm error on 2nd Zone
> after upgrading to 4.17.2
>
> After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM (and
> VRs) of the first zone upgraded without issues but the system VMs (s-318-VM
> and v-317-VM) of the second zone (Kitchener1) are no longer able to
> establish connection with the management server.  I have rebooted the host
> they are on, deleted the system vm to be recreated, I also logged into the
> two system VM and found nothing so far except fo the following management
> server logs:
>
> *2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
> (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM*
> *2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Failed to setup certificate for system vm: v-317-VM*
>
> The host of these 2 system VM was missed in the original update, such that
> is was updated after the Management Server was running with 4.17.2 instead
> of before.
>
> Would anyone have suggestion to resolve the issue?
>
>
> [image: Screenshot 2023-02-20 at 11.32.41 PM.png]
>
>
> 2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6
> job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq
> 44-1267200345151373322: Received:  { Ans: , MgmtId: 130593671224, via:
> 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer } }
> 2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid:
> "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state
> transited from [Starting] to [Running] with event [OperationSucceeded].
> VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid":
> "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host
> {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf",
> "type"="Routing"}, host before state transition: Host {"id": "44", "name":
> "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf",
> "type"="Routing"}
> 2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425
> job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq
> 44-1267200345151373326: Sending  { Cmd , MgmtId: 130593671224, via:
> 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.
> SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"
> router.name":"s-318-VM","Control":"169.254.254.63","Storage":"10.91.6.
> 249","Public":"64.32.40.68","Management":"10.91.0.244","
> router.ip":"169.254.254.63"},"wait":"60","bypassHostMaintenance":"false"}}]
> }
> 2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Start completed for VM VM instance {id: "317", name:
> "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a",
> type="ConsoleProxy"}
> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326:
> Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"
> org.apache.cloudstack.ca.SetupCertificateAnswer":{"
> result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425
> job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq
> 44-1267200345151373326: Received:  { Ans: , MgmtId: 130593671224, via:
> 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
> *2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
> (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM*
> 2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1)
> (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"
> dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"
> VirtualMachineManagerImpl"}
> 2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b)
> Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job
> origin: 20367
> 2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b)
> Remove job-20401 from job monitoring
> 2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
> (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm
> alert
> 2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter]
> (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up,
> zone: Kitchener1, secStorageVm: s-318-VM, public
> 2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl]
> (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19]
> dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm
> up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68,
> private IP: 10.91.0.244].
> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance
> {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87",
> type="SecondaryStorageVm"} was started.
> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl]
> (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is
> not even started, wait until next turn
> 2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6
> job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq
> 44-1267200345151373327: Sending  { Cmd , MgmtId: 130593671224, via:
> 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.
> SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"
> router.name":"v-317-VM","Control":"169.254.21.136","Public":"64.32.40.66"
> ,"Management":"10.91.0.237","router.ip":"169.254.21.136"},"wait":"60","
> bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978:
> Executing request
> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978:
> Response Received:
> 2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
> (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId:
> 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
> } }
> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl]
> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
> class com.cloud.agent.api.GetVolumeStatsCommand:
> 2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682:
> Executing request
> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache]
> (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682:
> Response Received:
> 2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
> (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId:
> 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
> } }
> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl]
> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
> class com.cloud.agent.api.GetVolumeStatsCommand:
> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327:
> Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"
> org.apache.cloudstack.ca.SetupCertificateAnswer":{"
> result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6
> job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq
> 44-1267200345151373327: Received:  { Ans: , MgmtId: 130593671224, via:
> 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
> *2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Failed to setup certificate for system vm: v-317-VM*
> 2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4)
> (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"
> dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"
> VirtualMachineManagerImpl"}
> 2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b)
> (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId:
> 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer
> } }
> 2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl]
> (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing
> class com.cloud.agent.api.GetVolumeStatsCommand:
> 2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9)
> Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job
> origin: 20366
> 2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor]
> (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9)
> Remove job-20400 from job monitoring
> 2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is
> started
> 2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq
> 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand"
> :{"_proxyVmId":"290","_loadInfo":"{
>   "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
> 2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone:
> Kitchener1, proxy: v-317-VM
> 2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq
> 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","
> bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl]
> (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10]
> dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in
> zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP:
> 10.91.0.237].
>
>
>
> Regards,
> *Antoine Boucher*
>
>
>

Re: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

Posted by Antoine Boucher <an...@haltondc.com>.
Here are the logs from daemon.log of the failing SSVM

Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed to locate executable /usr/local/cloud/systemvm/_run.sh: No such file or directory
Feb 21 02:36:16 systemvm systemd[1963]: cloud.service: Failed at step EXEC spawning /usr/local/cloud/systemvm/_run.sh: No such file or directory
Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Main process exited, code=exited, status=203/EXEC
Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Failed with result 'exit-code'.
Feb 21 02:36:16 systemvm systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Feb 21 02:36:16 systemvm systemd[1]: Finished Update UTMP about System Runlevel Changes.
Feb 21 02:36:16 systemvm systemd[1]: Startup finished in 2.285s (kernel) + 2min 16.468s (userspace) = 2min 18.754s.
Feb 21 02:36:16 systemvm systemd[1]: cloud.service: Scheduled restart job, restart counter is at 1.
Feb 21 02:36:16 systemvm systemd[1]: Stopped CloudStack Agent service.

This repeats 5 times and fails

The /usr/local/cloud/systemvm/ directory does not exist on the SSVM.  




Antoine Boucher
AntoineB@haltondc.com
[o] +1-226-505-9734
www.haltondc.com

“Data security made simple”





Confidentiality Warning: This message and any attachments are intended only for the use of the intended recipient(s), are confidential, and may be privileged. If you are not the intended recipient, you are hereby notified that any review, retransmission, conversion to hard copy, copying, circulation or other use of this message and any attachments is strictly prohibited. If you are not the intended recipient, please notify the sender immediately by return e-mail, and delete this message and any attachments from your system.


> On Feb 21, 2023, at 7:53 AM, Antoine Boucher <an...@haltondc.com> wrote:
> 
> They are not old they are the new ones.  I have deleted them a number of times after the upgrade but the issue prevails.  
> 
> Antoine Boucher
> AntoineB@haltondc.com
> [o] +1-226-505-9734
> www.haltondc.com
> 
> “Data security made simple and affordable”
> 
> 
> On Feb 21, 2023, at 00:24, Rohit Yadav <ro...@shapeblue.com> wrote:
> 
> 
> You can destroy these old systemvms or do a stop and start on them. 
> 
> Regards.
> 
>   
> 
>   
> From: Antoine Boucher <an...@haltondc.com>
> Sent: Tuesday, February 21, 2023 10:40:46 AM
> To: users <us...@cloudstack.apache.org>
> Subject: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2
>  
> After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM (and VRs) of the first zone upgraded without issues but the system VMs (s-318-VM and v-317-VM) of the second zone (Kitchener1) are no longer able to establish connection with the management server.  I have rebooted the host they are on, deleted the system vm to be recreated, I also logged into the two system VM and found nothing so far except fo the following management server logs:
> 
> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM 
> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
> 
> The host of these 2 system VM was missed in the original update, such that is was updated after the Management Server was running with 4.17.2 instead of before.
> 
> Would anyone have suggestion to resolve the issue?
> 
> 
> 
> 
> 
> 2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373322: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer } }
> 2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state transited from [Starting] to [Running] with event [OperationSucceeded]. VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, host before state transition: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}
> 2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name":"s-318-VM","Control":"169.254.254.63","Storage":"10.91.6.249","Public":"64.32.40.68","Management":"10.91.0.244","router.ip":"169.254.254.63"},"wait":"60","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Start completed for VM VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"}
> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
> 2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
> 2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"VirtualMachineManagerImpl"}
> 2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job origin: 20367
> 2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Remove job-20401 from job monitoring
> 2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm alert
> 2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up, zone: Kitchener1, secStorageVm: s-318-VM, public 
> 2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19] dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68, private IP: 10.91.0.244].
> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87", type="SecondaryStorageVm"} was started.
> 2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is not even started, wait until next turn
> 2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name":"v-317-VM","Control":"169.254.21.136","Public":"64.32.40.66","Management":"10.91.0.237","router.ip":"169.254.21.136"},"wait":"60","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978: Executing request
> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978: Response Received: 
> 2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId: 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
> 2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
> 2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682: Executing request
> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682: Response Received: 
> 2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId: 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
> 2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
> 2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
> 2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"VirtualMachineManagerImpl"}
> 2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId: 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
> 2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
> 2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job origin: 20366
> 2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Remove job-20400 from job monitoring
> 2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is started
> 2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"290","_loadInfo":"{
>   "connections": []
> }","wait":"0","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
> 2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone: Kitchener1, proxy: v-317-VM
> 2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
> 2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10] dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP: 10.91.0.237].
> 
> 
> 
> Regards,
> Antoine Boucher
> 


Re: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

Posted by Antoine Boucher <an...@haltondc.com>.
They are not old they are the new ones.  I have deleted them a number of times after the upgrade but the issue prevails.  

Antoine Boucher
AntoineB@haltondc.com
[o] +1-226-505-9734
www.haltondc.com

“Data security made simple and affordable”





Confidentiality Warning: This message and any attachments are intended only for the use of the intended recipient(s), are confidential, and may be privileged. If you are not the intended recipient, you are hereby notified that any review, retransmission, conversion to hard copy, copying, circulation or other use of this message and any attachments is strictly prohibited. If you are not the intended recipient, please notify the sender immediately by return e-mail, and delete this message and any attachments from your system.

On Feb 21, 2023, at 00:24, Rohit Yadav <ro...@shapeblue.com> wrote:


You can destroy these old systemvms or do a stop and start on them. 

Regards.

  

  

From: Antoine Boucher <an...@haltondc.com>
Sent: Tuesday, February 21, 2023 10:40:46 AM
To: users <us...@cloudstack.apache.org>
Subject: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2
 
After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM (and VRs) of the first zone upgraded without issues but the system VMs (s-318-VM and v-317-VM) of the second zone (Kitchener1) are no longer able to establish connection with the management server.  I have rebooted the host they are on, deleted the system vm to be recreated, I also logged into the two system VM and found nothing so far except fo the following management server logs:

2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM 
2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM

The host of these 2 system VM was missed in the original update, such that is was updated after the Management Server was running with 4.17.2 instead of before.

Would anyone have suggestion to resolve the issue?





2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373322: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer } }
2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state transited from [Starting] to [Running] with event [OperationSucceeded]. VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, host before state transition: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}
2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name":"s-318-VM","Control":"169.254.254.63","Storage":"10.91.6.249","Public":"64.32.40.68","Management":"10.91.0.244","router.ip":"169.254.254.63"},"wait":"60","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Start completed for VM VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"}
2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"VirtualMachineManagerImpl"}
2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job origin: 20367
2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Remove job-20401 from job monitoring
2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm alert
2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up, zone: Kitchener1, secStorageVm: s-318-VM, public 
2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19] dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68, private IP: 10.91.0.244].
2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87", type="SecondaryStorageVm"} was started.
2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is not even started, wait until next turn
2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name":"v-317-VM","Control":"169.254.21.136","Public":"64.32.40.66","Management":"10.91.0.237","router.ip":"169.254.21.136"},"wait":"60","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978: Executing request
2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978: Response Received: 
2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId: 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682: Executing request
2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682: Response Received: 
2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId: 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"VirtualMachineManagerImpl"}
2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId: 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand: 
2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job origin: 20366
2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Remove job-20400 from job monitoring
2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is started
2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"290","_loadInfo":"{
  "connections": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone: Kitchener1, proxy: v-317-VM
2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10] dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP: 10.91.0.237].



Regards,
Antoine Boucher


Re: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

Posted by Rohit Yadav <ro...@shapeblue.com>.
You can destroy these old systemvms or do a stop and start on them.

Regards.
________________________________
From: Antoine Boucher <an...@haltondc.com>
Sent: Tuesday, February 21, 2023 10:40:46 AM
To: users <us...@cloudstack.apache.org>
Subject: Failed to setup certificates for system vm error on 2nd Zone after upgrading to 4.17.2

After upgrading my two zone ACS from 4.16.2 to 4.17.2, the system VM (and VRs) of the first zone upgraded without issues but the system VMs (s-318-VM and v-317-VM) of the second zone (Kitchener1) are no longer able to establish connection with the management server.  I have rebooted the host they are on, deleted the system vm to be recreated, I also logged into the two system VM and found nothing so far except fo the following management server logs:

2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM

The host of these 2 system VM was missed in the original update, such that is was updated after the Management Server was running with 4.17.2 instead of before.

Would anyone have suggestion to resolve the issue?


[Screenshot 2023-02-20 at 11.32.41 PM.png]


2023-02-20 21:34:09,599 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373322: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { StartAnswer, CheckSshAnswer } }
2023-02-20 21:34:09,623 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"} state transited from [Starting] to [Running] with event [OperationSucceeded]. VM's original host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, new host: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}, host before state transition: Host {"id": "44", "name": "kit1-kvm03", "uuid": "3bde1185-8db6-414a-9c59-f788a2e0e9cf", "type"="Routing"}
2023-02-20 21:34:09,625 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name":"s-318-VM","Control":"169.254.254.63","Storage":"10.91.6.249","Public":"64.32.40.68","Management":"10.91.0.244","router.ip":"169.254.254.63"},"wait":"60","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:09,626 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Start completed for VM VM instance {id: "317", name: "v-317-VM", uuid: "0fbbd751-3bbe-46f6-bec0-e2887516fa6a", type="ConsoleProxy"}
2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (AgentManager-Handler-8:null) (logid:) Seq 44-1267200345151373326: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,063 DEBUG [c.c.a.t.Request] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Seq 44-1267200345151373326: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
2023-02-20 21:34:10,063 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Failed to setup certificate for system vm: s-318-VM
2023-02-20 21:34:10,064 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401 ctx-d67c7cd1) (logid:5d1ede3b) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":318,"handlerName":"VirtualMachineManagerImpl"}
2023-02-20 21:34:10,071 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 318, job origin: 20367
2023-02-20 21:34:10,072 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-15:ctx-34675425 job-20367/job-20401) (logid:5d1ede3b) Remove job-20401 from job monitoring
2023-02-20 21:34:10,081 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) received secondary storage vm alert
2023-02-20 21:34:10,082 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary Storage Vm is up, zone: Kitchener1, secStorageVm: s-318-VM, public
2023-02-20 21:34:10,083 WARN  [c.c.a.AlertManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) alertType=[19] dataCenterId=[4] podId=[4] clusterId=[null] message=[Secondary Storage Vm up in zone: Kitchener1, secStorageVm: s-318-VM, public IP: 64.32.40.68, private IP: 10.91.0.244].
2023-02-20 21:34:10,085 INFO  [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Secondary storage VM instance {id: "318", name: "s-318-VM", uuid: "be765f00-9b3f-47c8-b056-6a41e7befb87", type="SecondaryStorageVm"} was started.
2023-02-20 21:34:10,085 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-bedcece7) (logid:304260be) Primary secondary storage is not even started, wait until next turn
2023-02-20 21:34:10,433 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Sending  { Cmd , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":"false","accessDetails":{"router.name":"v-317-VM","Control":"169.254.21.136","Public":"64.32.40.66","Management":"10.91.0.237","router.ip":"169.254.21.136"},"wait":"60","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,622 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:63ad79d6) Seq 1-4502473727463655978: Executing request
2023-02-20 21:34:10,639 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-342:ctx-4fd75e0f) (logid:c3a060c9) Seq 1-4502473727463655978: Response Received:
2023-02-20 21:34:10,639 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 1-4502473727463655978: Received:  { Ans: , MgmtId: 130593671224, via: 1(cs-xcp01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,639 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand:
2023-02-20 21:34:10,682 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:65ac2df2) Seq 2-4712172585113094682: Executing request
2023-02-20 21:34:10,724 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-86:ctx-520aafa5) (logid:c3a060c9) Seq 2-4712172585113094682: Response Received:
2023-02-20 21:34:10,724 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 2-4712172585113094682: Received:  { Ans: , MgmtId: 130593671224, via: 2(cs-xcp02), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,724 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand:
2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) (logid:) Seq 44-1267200345151373327: Processing:  { Ans: , MgmtId: 130593671224, via: 44, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":"false","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,747 DEBUG [c.c.a.t.Request] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Seq 44-1267200345151373327: Received:  { Ans: , MgmtId: 130593671224, via: 44(kit1-kvm03), Ver: v1, Flags: 10, { SetupCertificateAnswer } }
2023-02-20 21:34:10,747 ERROR [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Failed to setup certificate for system vm: v-317-VM
2023-02-20 21:34:10,748 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400 ctx-d7f724f4) (logid:352477d9) Done executing VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":317,"handlerName":"VirtualMachineManagerImpl"}
2023-02-20 21:34:10,756 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Seq 9-6833649484581308478: Received:  { Ans: , MgmtId: 130593671224, via: 9(cs-kvm01), Ver: v1, Flags: 10, { GetVolumeStatsAnswer } }
2023-02-20 21:34:10,756 DEBUG [c.c.a.m.AgentManagerImpl] (StatsCollector-3:ctx-597a0e4b) (logid:c3a060c9) Details from executing class com.cloud.agent.api.GetVolumeStatsCommand:
2023-02-20 21:34:10,762 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 317, job origin: 20366
2023-02-20 21:34:10,764 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-14:ctx-502066d6 job-20366/job-20400) (logid:352477d9) Remove job-20400 from job monitoring
2023-02-20 21:34:10,773 INFO  [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy v-317-VM is started
2023-02-20 21:34:10,773 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Processing Seq 45-791665:  { Cmd , MgmtId: -1, via: 45, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"290","_loadInfo":"{
  "connections": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,773 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) received console proxy alert
2023-02-20 21:34:10,775 DEBUG [c.c.a.ConsoleProxyAlertAdapter] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) Console proxy is up, zone: Kitchener1, proxy: v-317-VM
2023-02-20 21:34:10,776 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid:) SeqA 45-791665: Sending Seq 45-791665:  { Ans: , MgmtId: 130593671224, via: 45, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2023-02-20 21:34:10,776 WARN  [c.c.a.AlertManagerImpl] (consoleproxy-1:ctx-2caa6d85) (logid:5554e671) alertType=[10] dataCenterId=[4] podId=[4] clusterId=[null] message=[Console proxy up in zone: Kitchener1, proxy: v-317-VM, public IP: 64.32.40.66, private IP: 10.91.0.237].



Regards,
Antoine Boucher