Re: SSVM stopped and will not be recreated.... :-(

[Jithin Raju]

Here it is:

https://github.com/apache/cloudstack/issues/7474



-Jithin

From: Jithin Raju <jithin.r...@shapeblue.com>
Date: Wednesday, 26 April 2023 at 1:52 PM
To: users@cloudstack.apache.org <users@cloudstack.apache.org>
Subject: Re: SSVM stopped and will not be recreated.... :-(
Hi Hari,

Yes, let me create one.

-Jithin

From: Harikrishna Patnala <harikrishna.patn...@shapeblue.com>
Date: Wednesday, 26 April 2023 at 12:36 PM
To: users@cloudstack.apache.org <users@cloudstack.apache.org>
Subject: Re: SSVM stopped and will not be recreated.... :-(
Hi Jithin,

Do we need to create an issue for that, seems fair to me to handle it properly.

Thanks,
Harikrishna

From: Jithin Raju <jithin.r...@shapeblue.com>
Date: Tuesday, 25 April 2023 at 11:05 AM
To: users@cloudstack.apache.org <users@cloudstack.apache.org>
Subject: Re: SSVM stopped and will not be recreated.... :-(
Hi David,

I came across similar issue where the new SSVM allocation fails since the newly 
added systemvm template in 4.17 during upgrade do not have its size set in 
vm_template and template_store_ref. Once you update these tables with the size 
value (from templates.properties in secondary storage) and recreate the 
SystemVMs it should go through.

Essentially any error during SSVM/CPVM allocation could leave that entry there 
without all the required allocation, when the secstorage-1 or the 
consoleproxy-1 thread runs again it would notice this entry as a stopped 
SSVM/CPVM and try starting it. Due to the previous error/s the volume is not 
allocated in this case hence the error “no usable volumes found” error while 
starting it since it doesn’t have entry for volume in the volumes table. This 
could be a bug.

-Jithin

From: Jithin Raju <jithin.r...@shapeblue.com>
Date: Tuesday, 25 April 2023 at 10:46 AM
To: users@cloudstack.apache.org <users@cloudstack.apache.org>
Subject: Re: SSVM stopped and will not be recreated.... :-(
Hi David,

Is that issue resolved? If not perform this:

tailf /var/log/cloudstack/management/management-server.log | grep secstorage-1

then destroy the existing SSVM and see if you see an error during the 
allocation of a new volume for the new SSVM?

-Jithin

From: Jithin Raju <jithin.r...@shapeblue.com>
Date: Wednesday, 19 April 2023 at 4:04 PM
To: users@cloudstack.apache.org <users@cloudstack.apache.org>
Subject: Re: SSVM stopped and will not be recreated.... :-(
Hi David,

Is it possible to share the complete log?

-Jithin

From: David Larsen <david.lar...@adcom.no>
Date: Tuesday, 18 April 2023 at 11:27 PM
To: users@cloudstack.apache.org <users@cloudstack.apache.org>
Subject: SV: SSVM stopped and will not be recreated.... :-(
Hi Jithin

Thanks
I tried to destroy the SSVM (s-1178-VM) again and the same happened.
When I destroyed the s-1178-VM,  a new secondarystoragevm  (s-1179-VM) is 
created in Cloudstack, but not in vmware. The new s-1179-VM have state 
"Stopped" in Cloudstack, the old s-1178-VM is gone from Cloudstack, but not in 
vmware...(?)
We are using vcenter 7.0.3 build 21290409, ESXi vsphere 7.0.3 build 20842708

When I search the logs, I see the "GetVolumeStatsCommand" is looking for an 
older secondarystoragevm (s-1177-VM).....(?)
Why is it asking for a destroyed secondarystoragevm?

Some logs bellow:

tail -f /var/log/cloudstack/management/management-server.log | grep secstorage
2023-04-18 18:42:06,457 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-5fbc0852) (logid:da43d2ce) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:42:36,452 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-46384dc3) (logid:d00b7246) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:43:06,455 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-4f4a13fd) (logid:7a2e9b74) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:43:36,455 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-cc2d5863) (logid:e71c579c) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:44:06,451 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1edf7982) (logid:eedb5033) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:44:06,455 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-1edf7982) (logid:eedb5033) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:44:06,458 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-1edf7982) (logid:eedb5033) Found SSVMs that are currently at 
stopping state, wait until they are settled
2023-04-18 18:44:36,459 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-82a430e4) (logid:463b8153) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:44:36,464 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-82a430e4) (logid:463b8153) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:44:36,468 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-82a430e4) (logid:463b8153) Found SSVMs that are currently at 
stopping state, wait until they are settled
2023-04-18 18:45:06,455 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:45:06,459 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:45:06,462 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:45:06,465 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:45:06,477 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:45:06,504 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) Sync job-13757 execution on object 
VmWorkJobQueue.1178
2023-04-18 18:45:08,480 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) received secondary storage vm alert
2023-04-18 18:45:08,482 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:45:08,483 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:45:08,506 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-18 18:45:36,454 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:45:36,458 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:45:36,461 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:45:36,465 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:45:36,467 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:45:36,488 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) Sync job-13758 execution on object 
VmWorkJobQueue.1178
2023-04-18 18:45:38,445 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) received secondary storage vm alert
2023-04-18 18:45:38,447 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:45:38,448 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:45:38,474 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-18 18:46:06,460 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:46:06,466 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:46:06,470 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:46:06,472 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) No stopped secondary storage VM is 
available, need to allocate a new secondary storage VM.
2023-04-18 18:46:06,476 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Assign secondary storage VM from a 
newly started instance for request from data center [5].
2023-04-18 18:46:06,539 DEBUG [o.a.c.e.o.NetworkOrchestrator] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Found existing network 
configuration for offering [Network Offering [1-Public-System-Public-Network]: 
Network {"id": 216, "name": "null", "uuid": 
"a576dbd7-4f3c-40b8-b38f-52a3fc020753", "networkofferingid": 1}
2023-04-18 18:46:06,539 DEBUG [o.a.c.e.o.NetworkOrchestrator] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Releasing lock for 
Acct[b68dbc82-e2f9-11e4-bc8e-005056b4469c-system] -- Account {"id": 1, "name": 
"system", "uuid": "b68dbc82-e2f9-11e4-bc8e-005056b4469c"}
2023-04-18 18:46:06,610 DEBUG [o.a.c.e.o.NetworkOrchestrator] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Found existing network 
configuration for offering [Network Offering 
[3-Control-System-Control-Network]: Network {"id": 218, "name": "null", "uuid": 
"dfedd93a-9259-4a40-95fe-83e77b999026", "networkofferingid": 3}
2023-04-18 18:46:06,610 DEBUG [o.a.c.e.o.NetworkOrchestrator] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Releasing lock for 
Acct[b68dbc82-e2f9-11e4-bc8e-005056b4469c-system] -- Account {"id": 1, "name": 
"system", "uuid": "b68dbc82-e2f9-11e4-bc8e-005056b4469c"}
2023-04-18 18:46:06,673 DEBUG [o.a.c.e.o.NetworkOrchestrator] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Found existing network 
configuration for offering [Network Offering 
[2-Management-System-Management-Network]: Network {"id": 217, "name": "null", 
"uuid": "014aeafe-c405-497e-8c28-9760e23ea2f9", "networkofferingid": 2}
2023-04-18 18:46:06,674 DEBUG [o.a.c.e.o.NetworkOrchestrator] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Releasing lock for 
Acct[b68dbc82-e2f9-11e4-bc8e-005056b4469c-system] -- Account {"id": 1, "name": 
"system", "uuid": "b68dbc82-e2f9-11e4-bc8e-005056b4469c"}
2023-04-18 18:46:06,788 INFO  [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) allocating virtual machine from 
template:27485b1b-225e-4888-baf8-1eea83534f8e with hostname:s-1179-VM and 3 
networks
2023-04-18 18:46:06,793 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Allocating entries for VM: VM 
instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}
2023-04-18 18:46:06,799 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Allocating nics for VM instance 
{id: "1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"}
2023-04-18 18:46:06,804 DEBUG [o.a.c.e.o.NetworkOrchestrator] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Allocating nic for vm VM instance 
{id: "1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} in network Network {"id": 216, "name": "null", 
"uuid": "a576dbd7-4f3c-40b8-b38f-52a3fc020753", "networkofferingid": 1} with 
requested profile NicProfile 
{"broadcastUri":null,"iPv4Address":null,"id":0,"reservationId":null,"vmId":0}
2023-04-18 18:46:06,849 DEBUG [c.c.u.d.T.Transaction] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Rolling back the transaction: Time 
= 47 Name =  secstorage-1; called by 
-TransactionLegacy.rollback:888-TransactionLegacy.removeUpTo:831-TransactionLegacy.close:655-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy70.persist:-1-NetworkOrchestrator.allocateNic:997-NetworkOrchestrator$3.addRequestedNicToNicListWithDeviceNumberAndRetrieveDefaultDevice:823-NetworkOrchestrator$3.doInTransactionWithoutResult:797
2023-04-18 18:46:06,863 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) received secondary storage vm alert
2023-04-18 18:46:06,865 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:46:06,867 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:46:06,887 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Unexpected exception DB Exception 
on: com.mysql.cj.jdbc.ClientPreparedStatement: INSERT INTO nics 
(nics.instance_id, nics.ip4_address, nics.ip6_address, nics.netmask, 
nics.isolation_uri, nics.ip_type, nics.broadcast_uri, nics.gateway, 
nics.mac_address, nics.mode, nics.network_id, nics.state, nics.reserver_name, 
nics.reservation_id, nics.device_id, nics.update_time, nics.default_nic, 
nics.ip6_gateway, nics.ip6_cidr, nics.strategy, nics.vm_type, nics.created, 
nics.uuid, nics.secondary_ip) VALUES (1179, x'3138352E3138372E32352E3137', 
null, x'3235352E3235352E3235352E30', 'vlan://307', 'Ip4', 'vlan://307', 
x'3138352E3138372E32352E31', x'31653A30303A64323A30303A30303A3362', 'Static', 
216, 'Allocated', x'5075626C69634E6574776F726B47757275', null, 2, null, 1, 
null, null, 'Create', 'SecondaryStorageVm', '2023-04-18 16:46:06', 
x'33666536323665352D633032302D346666382D616561652D376264626335383436306664', 0)
2023-04-18 18:46:36,457 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e383191) (logid:cb072098) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:46:36,460 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e383191) (logid:cb072098) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:46:36,464 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e383191) (logid:cb072098) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:46:36,466 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e383191) (logid:cb072098) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:46:36,469 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-1e383191) (logid:cb072098) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:46:36,502 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-1e383191) (logid:cb072098) Sync job-13761 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:46:38,641 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-1e383191) (logid:cb072098) received secondary storage vm alert
2023-04-18 18:46:38,643 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-1e383191) (logid:cb072098) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:46:38,645 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-1e383191) (logid:cb072098) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:46:38,687 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-1e383191) (logid:cb072098) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:47:06,458 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:47:06,462 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:47:06,465 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:47:06,469 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:47:06,472 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:47:06,492 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) Sync job-13762 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:47:08,585 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) received secondary storage vm alert
2023-04-18 18:47:08,587 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:47:08,588 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:47:08,606 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:47:36,457 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:47:36,464 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:47:36,468 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:47:36,472 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:47:36,477 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:47:36,505 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) Sync job-13763 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:47:38,507 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) received secondary storage vm alert
2023-04-18 18:47:38,508 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:47:38,510 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:47:38,528 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:48:06,461 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:48:06,465 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:48:06,468 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:48:06,470 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:48:06,473 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:48:06,493 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) Sync job-13764 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:48:08,549 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) received secondary storage vm alert
2023-04-18 18:48:08,551 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:48:08,552 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:48:08,576 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:48:36,458 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:48:36,462 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:48:36,465 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:48:36,468 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:48:36,471 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:48:36,490 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) Sync job-13765 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:48:38,546 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) received secondary storage vm alert
2023-04-18 18:48:38,548 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:48:38,549 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:48:38,583 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:49:06,455 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:49:06,460 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:49:06,463 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:49:06,466 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:49:06,468 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:49:06,489 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) Sync job-13766 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:49:08,520 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) received secondary storage vm alert
2023-04-18 18:49:08,522 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:49:08,524 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:49:08,548 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:49:36,452 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:49:36,456 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:49:36,458 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:49:36,461 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:49:36,463 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:49:36,484 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) Sync job-13767 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:49:38,559 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) received secondary storage vm alert
2023-04-18 18:49:38,561 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:49:38,562 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:49:38,586 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-1ceb1de7) (logid:44aa7ff8) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:50:06,461 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:50:06,465 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:50:06,467 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:50:06,470 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:50:06,472 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:50:06,493 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) Sync job-13768 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:50:08,520 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) received secondary storage vm alert
2023-04-18 18:50:08,521 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:50:08,522 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:50:08,557 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-8c3e85bb) (logid:0d1d11ba) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:50:36,452 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:50:36,456 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:50:36,459 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:50:36,461 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:50:36,464 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:50:36,500 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) Sync job-13769 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:50:38,515 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) received secondary storage vm alert
2023-04-18 18:50:38,516 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:50:38,517 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:50:38,541 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-d3294f3e) (logid:0fdb8e26) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:51:06,457 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) Zone [5] is ready to launch 
secondary storage VM.
2023-04-18 18:51:06,462 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) No running secondary storage vms 
found in datacenter id=5, starting one
2023-04-18 18:51:06,465 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) Allocate secondary storage VM 
standby capacity for zone [5].
2023-04-18 18:51:06,467 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:51:06,470 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) start parameter value of 
enterHardwareSetup == <very null> during processing of queued job
2023-04-18 18:51:06,493 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) Sync job-13770 execution on object 
VmWorkJobQueue.1179
2023-04-18 18:51:08,507 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) received secondary storage vm alert
2023-04-18 18:51:08,509 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) Secondary Storage Vm creation 
failure, zone: Zone1
2023-04-18 18:51:08,510 WARN  [c.c.a.AlertManagerImpl] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) alertType=[19] dataCenterId=[5] 
podId=[null] clusterId=[null] message=[Secondary Storage Vm creation failure. 
zone: Zone1, error details: Unable to allocate capacity on zone [5] due to 
[null].].
2023-04-18 18:51:08,532 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-5c50ef42) (logid:458db398) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].






tail -f  /var/log/cloudstack/management/management-server.log | grep SSVM
2023-04-18 18:43:12,797 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(qtp961160488-8581:ctx-af86395b ctx-a17f6e86) (logid:769564c4) submit async 
job-13753, details: AsyncJobVO: {id:13753, userId: 2, accountId: 2, 
instanceType: SystemVm, instanceId: 1177, cmd: 
org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: 
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"46285","id":"639b8cb6-63cd-47d3-b613-2cb7e01d8c93","ctxDetails":"{\"interface
 
com.cloud.vm.VirtualMachine\":\"639b8cb6-63cd-47d3-b613-2cb7e01d8c93\"}","ctxAccountId":"2","uuid":"639b8cb6-63cd-47d3-b613-2cb7e01d8c93","cmdEventType":"SSVM.DESTROY"},
 cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: 
null, initMsid: 345052051517, completeMsid: null, lastUpdated: null, 
lastPolled: null, created: null, removed: null}
2023-04-18 18:43:12,799 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753) (logid:d0cb3ffe) Executing 
AsyncJobVO: {id:13753, userId: 2, accountId: 2, instanceType: SystemVm, 
instanceId: 1177, cmd: 
org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: 
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"46285","id":"639b8cb6-63cd-47d3-b613-2cb7e01d8c93","ctxDetails":"{\"interface
 
com.cloud.vm.VirtualMachine\":\"639b8cb6-63cd-47d3-b613-2cb7e01d8c93\"}","ctxAccountId":"2","uuid":"639b8cb6-63cd-47d3-b613-2cb7e01d8c93","cmdEventType":"SSVM.DESTROY"},
 cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: 
null, initMsid: 345052051517, completeMsid: null, lastUpdated: null, 
lastPolled: null, created: null, removed: null}
2023-04-18 18:43:57,039 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(qtp961160488-4123:ctx-53cd4813 ctx-2bc943a3) (logid:1d4c8c32) submit async 
job-13755, details: AsyncJobVO: {id:13755, userId: 2, accountId: 2, 
instanceType: SystemVm, instanceId: 1178, cmd: 
org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: 
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"46288","id":"457e6f90-8bb1-4026-b908-b555511951f6","ctxDetails":"{\"interface
 
com.cloud.vm.VirtualMachine\":\"457e6f90-8bb1-4026-b908-b555511951f6\"}","ctxAccountId":"2","uuid":"457e6f90-8bb1-4026-b908-b555511951f6","cmdEventType":"SSVM.DESTROY"},
 cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: 
null, initMsid: 345052051517, completeMsid: null, lastUpdated: null, 
lastPolled: null, created: null, removed: null}
2023-04-18 18:43:57,039 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(API-Job-Executor-7:ctx-ba0497f6 job-13755) (logid:232d55e7) Executing 
AsyncJobVO: {id:13755, userId: 2, accountId: 2, instanceType: SystemVm, 
instanceId: 1178, cmd: 
org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: 
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"46288","id":"457e6f90-8bb1-4026-b908-b555511951f6","ctxDetails":"{\"interface
 
com.cloud.vm.VirtualMachine\":\"457e6f90-8bb1-4026-b908-b555511951f6\"}","ctxAccountId":"2","uuid":"457e6f90-8bb1-4026-b908-b555511951f6","cmdEventType":"SSVM.DESTROY"},
 cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: 
null, initMsid: 345052051517, completeMsid: null, lastUpdated: null, 
lastPolled: null, created: null, removed: null}
2023-04-18 18:44:06,458 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-1edf7982) (logid:eedb5033) Found SSVMs that are currently at 
stopping state, wait until they are settled
2023-04-18 18:44:36,468 INFO  [o.a.c.s.PremiumSecondaryStorageManagerImpl] 
(secstorage-1:ctx-82a430e4) (logid:463b8153) Found SSVMs that are currently at 
stopping state, wait until they are settled
2023-04-18 18:45:44,364 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(qtp961160488-8581:ctx-9ea16096 ctx-a9002084) (logid:bf6dd1c0) submit async 
job-13759, details: AsyncJobVO: {id:13759, userId: 2, accountId: 2, 
instanceType: SystemVm, instanceId: 1178, cmd: 
org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: 
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"46291","id":"457e6f90-8bb1-4026-b908-b555511951f6","ctxDetails":"{\"interface
 
com.cloud.vm.VirtualMachine\":\"457e6f90-8bb1-4026-b908-b555511951f6\"}","ctxAccountId":"2","uuid":"457e6f90-8bb1-4026-b908-b555511951f6","cmdEventType":"SSVM.DESTROY"},
 cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: 
null, initMsid: 345052051517, completeMsid: null, lastUpdated: null, 
lastPolled: null, created: null, removed: null}
2023-04-18 18:45:44,366 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(API-Job-Executor-8:ctx-abbbf5d6 job-13759) (logid:3acba51f) Executing 
AsyncJobVO: {id:13759, userId: 2, accountId: 2, instanceType: SystemVm, 
instanceId: 1178, cmd: 
org.apache.cloudstack.api.command.admin.systemvm.DestroySystemVmCmd, cmdInfo: 
{"response":"json","ctxUserId":"2","httpmethod":"GET","ctxStartEventId":"46291","id":"457e6f90-8bb1-4026-b908-b555511951f6","ctxDetails":"{\"interface
 
com.cloud.vm.VirtualMachine\":\"457e6f90-8bb1-4026-b908-b555511951f6\"}","ctxAccountId":"2","uuid":"457e6f90-8bb1-4026-b908-b555511951f6","cmdEventType":"SSVM.DESTROY"},
 cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: 
null, initMsid: 345052051517, completeMsid: null, lastUpdated: null, 
lastPolled: null, created: null, removed: null}







tail -f /var/log/cloudstack/management/management-server.log | grep s-117
2023-04-18 18:34:05,751 INFO  [c.c.h.v.m.VirtualMachineMO] 
(DirectAgent-97:ctx-8961729c *.*.*31, cmd: GetVolumeStatsCommand) 
(logid:c45bc0cb) Test against disk backing : [FS_Volume4] 
s-1177-VM/ROOT-1177_2.vmdk
2023-04-18 18:34:05,751 INFO  [c.c.h.v.m.VirtualMachineMO] 
(DirectAgent-97:ctx-8961729c *.*.*31, cmd: GetVolumeStatsCommand) 
(logid:c45bc0cb) Disk backing : [FS_Volume4] s-1177-VM/ROOT-1177_2.vmdk matches 
==> scsi0:0
2023-04-18 18:34:05,755 DEBUG [c.c.h.v.m.DatastoreMO] 
(DirectAgent-97:ctx-8961729c *.*.*31, cmd: GetVolumeStatsCommand) 
(logid:c45bc0cb) Search file ROOT-1177_2.vmdk on [FS_Volume4] s-1177-VM
2023-04-18 18:34:05,771 INFO  [c.c.h.v.u.VmwareHelper] 
(DirectAgent-97:ctx-8961729c *.*.*31, cmd: GetVolumeStatsCommand) 
(logid:c45bc0cb) [ignored]failed to get message for exception: File 
[FS_Volume4] s-1177-VM was not found
Message: File [FS_Volume4] s-1177-VM was not found
java.lang.RuntimeException: File [FS_Volume4] s-1177-VM was not found
2023-04-18 18:43:14,244 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-3:ctx-952705c4 job-13753/job-13754 ctx-73806fdc) 
(logid:d0cb3ffe) Stopped called on VM instance {id: "1177", name: "s-1177-VM", 
uuid: "639b8cb6-63cd-47d3-b613-2cb7e01d8c93", type="SecondaryStorageVm"} but 
the state is Destroyed
2023-04-18 18:43:14,340 DEBUG [c.c.c.CapacityManagerImpl] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753 ctx-311e2f61) (logid:d0cb3ffe) VM 
instance {id: "1177", name: "s-1177-VM", uuid: 
"639b8cb6-63cd-47d3-b613-2cb7e01d8c93", type="SecondaryStorageVm"} state 
transited from [Destroyed] to [Expunging] with event [ExpungeOperation]. VM's 
original host: Host {"id": "2", "name": "*.*.*31", "uuid": 
"d55e6015-8a9e-4248-b568-20326d986b5f", "type"="Routing"}, new host: Host 
{"id": "2", "name": "*.*.*31", "uuid": "d55e6015-8a9e-4248-b568-20326d986b5f", 
"type"="Routing"}, host before state transition: Host {"id": "2", "name": 
"*.*.*31", "uuid": "d55e6015-8a9e-4248-b568-20326d986b5f", "type"="Routing"}
2023-04-18 18:43:14,348 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753 ctx-311e2f61) (logid:d0cb3ffe) 
Destroying vm VM instance {id: "1177", name: "s-1177-VM", uuid: 
"639b8cb6-63cd-47d3-b613-2cb7e01d8c93", type="SecondaryStorageVm"}
2023-04-18 18:43:14,349 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753 ctx-311e2f61) (logid:d0cb3ffe) 
Cleaning up NICS [] of VM instance {id: "1177", name: "s-1177-VM", uuid: 
"639b8cb6-63cd-47d3-b613-2cb7e01d8c93", type="SecondaryStorageVm"}.
2023-04-18 18:43:14,651 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753 ctx-311e2f61) (logid:d0cb3ffe) 
Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed 
storage. Data from VM instance {id: "1177", name: "s-1177-VM", uuid: 
"639b8cb6-63cd-47d3-b613-2cb7e01d8c93", type="SecondaryStorageVm"}.
2023-04-18 18:43:14,771 DEBUG [c.c.a.t.Request] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753 ctx-311e2f61) (logid:d0cb3ffe) Seq 
2-2008042483853822869: Sending  { Cmd , MgmtId: 345052051517, via: 2(*.*.*31), 
Ver: v1, Flags: 100011, 
[{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"512f50e8-2aa3-4e00-b0c4-e1b59c6e7ef8","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"52c5eb30-fe06-3482-93d4-27a566915de3","name":"FS_Volume4","id":"13","poolType":"PreSetup","host":"*.*.*55","path":"/Troll-ITData-Datacenter/FS_Volume4","port":"0","url":"PreSetup://*.*.*55/Troll-ITData-Datacenter/FS_Volume4/?ROLE=Primary&STOREUUID=52c5eb30-fe06-3482-93d4-27a566915de3","isManaged":"false"}},"name":"ROOT-1177","size":"(4.88
 GB) 
5242880000","path":"ROOT-1177_2","volumeId":"1534","vmName":"s-1177-VM","accountId":"1","chainInfo":"{"diskDeviceBusName":"scsi0:0","diskChain":["[FS_Volume4]
 
s-1177-VM/ROOT-1177_2.vmdk"]}","format":"OVA","provisioningType":"THIN","poolId":"13","id":"1534","deviceId":"0","hypervisorType":"VMware","directDownload":"false","deployAsIs":"false"}},"wait":"0","bypassHostMaintenance":"true"}}]
 }
2023-04-18 18:43:14,772 DEBUG [c.c.a.t.Request] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753 ctx-311e2f61) (logid:d0cb3ffe) Seq 
2-2008042483853822869: Executing:  { Cmd , MgmtId: 345052051517, via: 
2(*.*.*31), Ver: v1, Flags: 100011, 
[{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"512f50e8-2aa3-4e00-b0c4-e1b59c6e7ef8","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"52c5eb30-fe06-3482-93d4-27a566915de3","name":"FS_Volume4","id":"13","poolType":"PreSetup","host":"*.*.*55","path":"/Troll-ITData-Datacenter/FS_Volume4","port":"0","url":"PreSetup://*.*.*55/Troll-ITData-Datacenter/FS_Volume4/?ROLE=Primary&STOREUUID=52c5eb30-fe06-3482-93d4-27a566915de3","isManaged":"false"}},"name":"ROOT-1177","size":"(4.88
 GB) 
5242880000","path":"ROOT-1177_2","volumeId":"1534","vmName":"s-1177-VM","accountId":"1","chainInfo":"{"diskDeviceBusName":"scsi0:0","diskChain":["[FS_Volume4]
 
s-1177-VM/ROOT-1177_2.vmdk"]}","format":"OVA","provisioningType":"THIN","poolId":"13","id":"1534","deviceId":"0","hypervisorType":"VMware","directDownload":"false","deployAsIs":"false"}},"wait":"0","bypassHostMaintenance":"true"}}]
 }
2023-04-18 18:43:14,772 DEBUG [c.c.h.v.r.VmwareResource] 
(DirectAgent-140:ctx-bf63dddc) (logid:d0cb3ffe) Executing resource command 
DeleteCommand: 
[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"512f50e8-2aa3-4e00-b0c4-e1b59c6e7ef8","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"52c5eb30-fe06-3482-93d4-27a566915de3","name":"FS_Volume4","id":13,"poolType":"PreSetup","host":"*.*.*55","path":"/Troll-ITData-Datacenter/FS_Volume4","port":0,"url":"PreSetup://*.*.*55/Troll-ITData-Datacenter/FS_Volume4/?ROLE=Primary&STOREUUID=52c5eb30-fe06-3482-93d4-27a566915de3","isManaged":false}},"name":"ROOT-1177","size":5242880000,"path":"ROOT-1177_2","volumeId":1534,"vmName":"s-1177-VM","accountId":1,"chainInfo":"{\"diskDeviceBusName\":\"scsi0:0\",\"diskChain\":[\"[FS_Volume4]
 
s-1177-VM/ROOT-1177_2.vmdk\"]}","format":"OVA","provisioningType":"THIN","poolId":13,"id":1534,"deviceId":0,"hypervisorType":"VMware","directDownload":false,"deployAsIs":false}},"wait":0,"bypassHostMaintenance":true}].
2023-04-18 18:43:14,773 DEBUG [c.c.s.r.StorageSubsystemCommandHandlerBase] 
(DirectAgent-140:ctx-bf63dddc *.*.*31, job-13753, cmd: DeleteCommand) 
(logid:d0cb3ffe) Executing command DeleteCommand: 
[{"data":{"uuid":"512f50e8-2aa3-4e00-b0c4-e1b59c6e7ef8","volumeType":"ROOT","dataStore":{"uuid":"52c5eb30-fe06-3482-93d4-27a566915de3","name":"FS_Volume4","id":13,"poolType":"PreSetup","host":"*.*.*55","path":"/Troll-ITData-Datacenter/FS_Volume4","port":0,"url":"PreSetup://*.*.*55/Troll-ITData-Datacenter/FS_Volume4/?ROLE\u003dPrimary\u0026STOREUUID\u003d52c5eb30-fe06-3482-93d4-27a566915de3","isManaged":false},"name":"ROOT-1177","size":5242880000,"path":"ROOT-1177_2","volumeId":1534,"vmName":"s-1177-VM","accountId":1,"chainInfo":"{\"diskDeviceBusName\":\"scsi0:0\",\"diskChain\":[\"[FS_Volume4]
 
s-1177-VM/ROOT-1177_2.vmdk\"]}","format":"OVA","provisioningType":"THIN","poolId":13,"id":1534,"deviceId":0,"hypervisorType":"VMware","directDownload":false,"deployAsIs":false},"contextMap":{"logid":"d0cb3ffe","job":"job-13753"},"wait":0,"bypassHostMaintenance":true}].
2023-04-18 18:43:14,835 INFO  [c.c.s.r.VmwareStorageProcessor] 
(DirectAgent-140:ctx-bf63dddc *.*.*31, job-13753, cmd: DeleteCommand) 
(logid:d0cb3ffe) Destroy root volume and VM itself. vmName s-1177-VM
2023-04-18 18:43:15,023 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753 ctx-311e2f61) (logid:d0cb3ffe) 
Expunged VM instance {id: "1177", name: "s-1177-VM", uuid: 
"639b8cb6-63cd-47d3-b613-2cb7e01d8c93", type="SecondaryStorageVm"}
2023-04-18 18:43:15,075 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(API-Job-Executor-6:ctx-bbfa0329 job-13753 ctx-311e2f61) (logid:d0cb3ffe) 
Complete async job-13753, jobStatus: SUCCEEDED, resultCode: 0, result: 
org.apache.cloudstack.api.response.SystemVmResponse/systemvm/{"id":"639b8cb6-63cd-47d3-b613-2cb7e01d8c93","systemvmtype":"secondarystoragevm","zoneid":"3f01aeee-20c4-4781-affd-3b748094c312","zonename":"Zone1","dns1":"8.8.8.8","name":"s-1177-VM","podid":"d4bf1db2-972d-4882-93a9-d75a7a8e0b33","podname":"A6","hostid":"d55e6015-8a9e-4248-b568-20326d986b5f","hostname":"*.*.*31","hypervisor":"VMware","templateid":"27485b1b-225e-4888-baf8-1eea83534f8e","templatename":"systemvm-vmware-4.17.2","created":"2023-03-29T23:01:44+0200","state":"Destroyed","isdynamicallyscalable":"false","hasannotations":"false"}
2023-04-18 18:43:57,861 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-209:ctx-28ecfe9d) (logid:3498a4cc) Unable to find matched 
VM in CloudStack DB. name: s-1177-VM
2023-04-18 18:43:58,285 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-4:ctx-0e951968 job-13755/job-13756 ctx-e7e7f427) 
(logid:232d55e7) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Running] to [Stopping] with event [StopRequested]. VM's 
original host: Host {"id": "42", "name": "*.*.*29", "uuid": 
"41fe5bec-f86a-4b67-87aa-6247fd8de621", "type"="Routing"}, new host: Host 
{"id": "2", "name": "*.*.*31", "uuid": "d55e6015-8a9e-4248-b568-20326d986b5f", 
"type"="Routing"}, host before state transition: Host {"id": "2", "name": 
"*.*.*31", "uuid": "d55e6015-8a9e-4248-b568-20326d986b5f", "type"="Routing"}
2023-04-18 18:44:57,831 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-421:ctx-ab65ac45) (logid:0424fbce) Unable to find matched 
VM in CloudStack DB. name: s-1177-VM
2023-04-18 18:44:57,973 INFO  [c.c.v.VirtualMachineManagerImpl] 
(DirectAgentCronJob-421:ctx-ab65ac45) (logid:0424fbce) VM s-1178-VM is at 
Stopping and we received a PowerOn report while there is no pending jobs on it
2023-04-18 18:44:57,994 DEBUG [c.c.c.CapacityManagerImpl] 
(DirectAgentCronJob-421:ctx-ab65ac45) (logid:0424fbce) VM instance {id: "1178", 
name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} state transited from [Stopping] to [Stopped] with 
event [FollowAgentPowerOffReport]. VM's original host: Host {"id": "42", 
"name": "*.*.*29", "uuid": "41fe5bec-f86a-4b67-87aa-6247fd8de621", 
"type"="Routing"}, new host: null, host before state transition: Host {"id": 
"2", "name": "*.*.*31", "uuid": "d55e6015-8a9e-4248-b568-20326d986b5f", 
"type"="Routing"}
2023-04-18 18:44:58,926 INFO  [c.c.v.VirtualMachineManagerImpl] 
(DirectAgentCronJob-421:ctx-ab65ac45) (logid:0424fbce) VM s-1178-VM is sync-ed 
to at Stopped state according to power-off report from hypervisor
2023-04-18 18:45:06,465 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:45:08,247 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-5:ctx-87c42ae1 job-13745/job-13757 ctx-102f7064) 
(logid:bc71db15) orchestrating VM start for 's-1178-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-04-18 18:45:08,262 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-5:ctx-87c42ae1 job-13745/job-13757 ctx-102f7064) 
(logid:bc71db15) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: Host {"id": "42", "name": "*.*.*29", "uuid": 
"41fe5bec-f86a-4b67-87aa-6247fd8de621", "type"="Routing"}, new host: null, host 
before state transition: null
2023-04-18 18:45:08,263 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-5:ctx-87c42ae1 job-13745/job-13757 ctx-102f7064) 
(logid:bc71db15) Successfully transitioned to start state for VM instance {id: 
"1178", name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} reservation id = 4df554e2-7b6a-4316-9c2b-4517e8d39f3d
2023-04-18 18:45:08,396 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-5:ctx-87c42ae1 job-13745/job-13757 ctx-102f7064) 
(logid:bc71db15) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: Host {"id": "42", "name": "*.*.*29", "uuid": 
"41fe5bec-f86a-4b67-87aa-6247fd8de621", "type"="Routing"}, new host: null, host 
before state transition: null
2023-04-18 18:45:08,399 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-5:ctx-87c42ae1 job-13745/job-13757 ctx-102f7064) 
(logid:bc71db15) Unable to orchestrate start VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1178].
2023-04-18 18:45:08,506 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-36cf6e8c) (logid:56ad8856) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-18 18:45:36,465 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:45:38,245 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-6:ctx-d6e26cd0 job-13745/job-13758 ctx-49c24495) 
(logid:bc71db15) orchestrating VM start for 's-1178-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-04-18 18:45:38,253 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-6:ctx-d6e26cd0 job-13745/job-13758 ctx-49c24495) 
(logid:bc71db15) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: Host {"id": "42", "name": "*.*.*29", "uuid": 
"41fe5bec-f86a-4b67-87aa-6247fd8de621", "type"="Routing"}, new host: null, host 
before state transition: null
2023-04-18 18:45:38,254 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-6:ctx-d6e26cd0 job-13745/job-13758 ctx-49c24495) 
(logid:bc71db15) Successfully transitioned to start state for VM instance {id: 
"1178", name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} reservation id = 15c5b81c-4190-4ef4-b3b6-3bdb3eb16816
2023-04-18 18:45:38,363 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-6:ctx-d6e26cd0 job-13745/job-13758 ctx-49c24495) 
(logid:bc71db15) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: Host {"id": "42", "name": "*.*.*29", "uuid": 
"41fe5bec-f86a-4b67-87aa-6247fd8de621", "type"="Routing"}, new host: null, host 
before state transition: null
2023-04-18 18:45:38,365 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-6:ctx-d6e26cd0 job-13745/job-13758 ctx-49c24495) 
(logid:bc71db15) Unable to orchestrate start VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1178].
2023-04-18 18:45:38,474 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-1e85449e) (logid:5c0bed1c) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-18 18:45:46,237 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-7:ctx-19854a12 job-13759/job-13760 ctx-c3bc51d4) 
(logid:3acba51f) VM is already stopped: VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"}
2023-04-18 18:45:46,323 DEBUG [c.c.c.CapacityManagerImpl] 
(API-Job-Executor-8:ctx-abbbf5d6 job-13759 ctx-0ef84f4e) (logid:3acba51f) VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Expunging] with event [ExpungeOperation]. VM's 
original host: Host {"id": "42", "name": "*.*.*29", "uuid": 
"41fe5bec-f86a-4b67-87aa-6247fd8de621", "type"="Routing"}, new host: null, host 
before state transition: null
2023-04-18 18:45:46,349 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(API-Job-Executor-8:ctx-abbbf5d6 job-13759 ctx-0ef84f4e) (logid:3acba51f) 
Destroying vm VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}
2023-04-18 18:45:46,349 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(API-Job-Executor-8:ctx-abbbf5d6 job-13759 ctx-0ef84f4e) (logid:3acba51f) 
Cleaning up NICS [] of VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}.
2023-04-18 18:45:46,352 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(API-Job-Executor-8:ctx-abbbf5d6 job-13759 ctx-0ef84f4e) (logid:3acba51f) 
Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed 
storage. Data from VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}.
2023-04-18 18:45:46,383 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(API-Job-Executor-8:ctx-abbbf5d6 job-13759 ctx-0ef84f4e) (logid:3acba51f) 
Expunged VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}
2023-04-18 18:45:46,451 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] 
(API-Job-Executor-8:ctx-abbbf5d6 job-13759 ctx-0ef84f4e) (logid:3acba51f) 
Complete async job-13759, jobStatus: SUCCEEDED, resultCode: 0, result: 
org.apache.cloudstack.api.response.SystemVmResponse/systemvm/{"id":"457e6f90-8bb1-4026-b908-b555511951f6","systemvmtype":"secondarystoragevm","zoneid":"3f01aeee-20c4-4781-affd-3b748094c312","zonename":"Zone1","dns1":"8.8.8.8","name":"s-1178-VM","podid":"d4bf1db2-972d-4882-93a9-d75a7a8e0b33","podname":"A6","hypervisor":"VMware","templateid":"27485b1b-225e-4888-baf8-1eea83534f8e","templatename":"systemvm-vmware-4.17.2","created":"2023-04-17T21:30:24+0200","state":"Stopped","isdynamicallyscalable":"false","hasannotations":"false"}
2023-04-18 18:45:57,831 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-53:ctx-d7af3059) (logid:239316df) Unable to find matched VM 
in CloudStack DB. name: s-1178-VM
2023-04-18 18:45:57,861 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-53:ctx-d7af3059) (logid:239316df) Unable to find matched VM 
in CloudStack DB. name: s-1177-VM
2023-04-18 18:46:06,788 INFO  [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) allocating virtual machine from 
template:27485b1b-225e-4888-baf8-1eea83534f8e with hostname:s-1179-VM and 3 
networks
2023-04-18 18:46:06,793 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Allocating entries for VM: VM 
instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}
2023-04-18 18:46:06,799 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Allocating nics for VM instance 
{id: "1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"}
2023-04-18 18:46:06,804 DEBUG [o.a.c.e.o.NetworkOrchestrator] 
(secstorage-1:ctx-c59fadd5) (logid:0f24bd69) Allocating nic for vm VM instance 
{id: "1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} in network Network {"id": 216, "name": "null", 
"uuid": "a576dbd7-4f3c-40b8-b38f-52a3fc020753", "networkofferingid": 1} with 
requested profile NicProfile 
{"broadcastUri":null,"iPv4Address":null,"id":0,"reservationId":null,"vmId":0}
2023-04-18 18:46:36,466 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-1e383191) (logid:cb072098) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:46:38,262 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-8:ctx-3c89f0e7 job-13745/job-13761 ctx-7c0b8e24) 
(logid:bc71db15) orchestrating VM start for 's-1179-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-04-18 18:46:38,273 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-8:ctx-3c89f0e7 job-13745/job-13761 ctx-7c0b8e24) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:46:38,274 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-8:ctx-3c89f0e7 job-13745/job-13761 ctx-7c0b8e24) 
(logid:bc71db15) Successfully transitioned to start state for VM instance {id: 
"1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} reservation id = 18f7b100-d721-4640-bf38-3085d8f94853
2023-04-18 18:46:38,558 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-8:ctx-3c89f0e7 job-13745/job-13761 ctx-7c0b8e24) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:46:38,560 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-8:ctx-3c89f0e7 job-13745/job-13761 ctx-7c0b8e24) 
(logid:bc71db15) Unable to orchestrate start VM instance {id: "1179", name: 
"s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1179].
2023-04-18 18:46:38,687 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-1e383191) (logid:cb072098) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:46:57,794 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-426:ctx-632e9e90) (logid:b9590064) Unable to find matched 
VM in CloudStack DB. name: s-1178-VM
2023-04-18 18:46:57,827 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-426:ctx-632e9e90) (logid:b9590064) Unable to find matched 
VM in CloudStack DB. name: s-1177-VM
2023-04-18 18:47:06,469 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:47:08,260 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-9:ctx-cb579101 job-13745/job-13762 ctx-0292e8fe) 
(logid:bc71db15) orchestrating VM start for 's-1179-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-04-18 18:47:08,269 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-9:ctx-cb579101 job-13745/job-13762 ctx-0292e8fe) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:47:08,269 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-9:ctx-cb579101 job-13745/job-13762 ctx-0292e8fe) 
(logid:bc71db15) Successfully transitioned to start state for VM instance {id: 
"1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} reservation id = e1cbbece-94f2-4c84-a630-12bf56ed13c6
2023-04-18 18:47:08,499 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-9:ctx-cb579101 job-13745/job-13762 ctx-0292e8fe) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:47:08,502 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-9:ctx-cb579101 job-13745/job-13762 ctx-0292e8fe) 
(logid:bc71db15) Unable to orchestrate start VM instance {id: "1179", name: 
"s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1179].
2023-04-18 18:47:08,606 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-bb1873d2) (logid:78c589d1) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:47:36,472 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:47:38,247 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-10:ctx-67232ad1 job-13745/job-13763 ctx-1605a30a) 
(logid:bc71db15) orchestrating VM start for 's-1179-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-04-18 18:47:38,257 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-10:ctx-67232ad1 job-13745/job-13763 ctx-1605a30a) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:47:38,258 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-10:ctx-67232ad1 job-13745/job-13763 ctx-1605a30a) 
(logid:bc71db15) Successfully transitioned to start state for VM instance {id: 
"1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} reservation id = 1a3b6a60-844d-4264-8086-013443c85298
2023-04-18 18:47:38,427 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-10:ctx-67232ad1 job-13745/job-13763 ctx-1605a30a) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:47:38,429 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-10:ctx-67232ad1 job-13745/job-13763 ctx-1605a30a) 
(logid:bc71db15) Unable to orchestrate start VM instance {id: "1179", name: 
"s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1179].
2023-04-18 18:47:38,528 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-e3820dd6) (logid:d0f25a26) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:47:57,808 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-214:ctx-06a78c35) (logid:de61ec01) Unable to find matched 
VM in CloudStack DB. name: s-1178-VM
2023-04-18 18:47:57,843 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-214:ctx-06a78c35) (logid:de61ec01) Unable to find matched 
VM in CloudStack DB. name: s-1177-VM
2023-04-18 18:48:06,470 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:48:08,246 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-11:ctx-bd96ab5d job-13745/job-13764 ctx-1a265ab4) 
(logid:bc71db15) orchestrating VM start for 's-1179-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-04-18 18:48:08,257 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-11:ctx-bd96ab5d job-13745/job-13764 ctx-1a265ab4) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:48:08,257 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-11:ctx-bd96ab5d job-13745/job-13764 ctx-1a265ab4) 
(logid:bc71db15) Successfully transitioned to start state for VM instance {id: 
"1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} reservation id = 3e56b64d-57fd-4913-87f7-b450be86a52a
2023-04-18 18:48:08,445 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-11:ctx-bd96ab5d job-13745/job-13764 ctx-1a265ab4) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:48:08,449 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-11:ctx-bd96ab5d job-13745/job-13764 ctx-1a265ab4) 
(logid:bc71db15) Unable to orchestrate start VM instance {id: "1179", name: 
"s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1179].
2023-04-18 18:48:08,576 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-b6a8e628) (logid:24aa8d71) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:48:36,468 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:48:38,268 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-12:ctx-ed2abbb3 job-13745/job-13765 ctx-b6bf17a8) 
(logid:bc71db15) orchestrating VM start for 's-1179-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-04-18 18:48:38,281 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-12:ctx-ed2abbb3 job-13745/job-13765 ctx-b6bf17a8) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:48:38,282 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-12:ctx-ed2abbb3 job-13745/job-13765 ctx-b6bf17a8) 
(logid:bc71db15) Successfully transitioned to start state for VM instance {id: 
"1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} reservation id = 3bc0eaa6-e63f-436b-85ef-1d68a52c4d6d
2023-04-18 18:48:38,466 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-12:ctx-ed2abbb3 job-13745/job-13765 ctx-b6bf17a8) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:48:38,469 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-12:ctx-ed2abbb3 job-13745/job-13765 ctx-b6bf17a8) 
(logid:bc71db15) Unable to orchestrate start VM instance {id: "1179", name: 
"s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1179].
2023-04-18 18:48:38,583 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-c2604b41) (logid:d3120d5a) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
2023-04-18 18:48:57,794 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-431:ctx-ea6602ab) (logid:55790097) Unable to find matched 
VM in CloudStack DB. name: s-1178-VM
2023-04-18 18:48:57,827 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] 
(DirectAgentCronJob-431:ctx-ea6602ab) (logid:55790097) Unable to find matched 
VM in CloudStack DB. name: s-1177-VM
2023-04-18 18:49:06,466 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) Found a stopped secondary storage 
VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"}, starting it.
2023-04-18 18:49:08,256 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-13:ctx-047742c6 job-13745/job-13766 ctx-04720e77) 
(logid:bc71db15) orchestrating VM start for 's-1179-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d set to null
2023-04-18 18:49:08,269 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-13:ctx-047742c6 job-13745/job-13766 ctx-04720e77) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:49:08,270 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-13:ctx-047742c6 job-13745/job-13766 ctx-04720e77) 
(logid:bc71db15) Successfully transitioned to start state for VM instance {id: 
"1179", name: "s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} reservation id = f3b7a6c6-f797-43b6-87a9-fd11de9f1e50
2023-04-18 18:49:08,439 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-13:ctx-047742c6 job-13745/job-13766 ctx-04720e77) 
(logid:bc71db15) VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-18 18:49:08,441 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-13:ctx-047742c6 job-13745/job-13766 ctx-04720e77) 
(logid:bc71db15) Unable to orchestrate start VM instance {id: "1179", name: 
"s-1179-VM", uuid: "44962385-e324-4eda-941e-526ed6fa3cab", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1179].
2023-04-18 18:49:08,548 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-59a5b577) (logid:20dc9b7c) Unexpected exception Unable to 
orchestrate start VM instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1179", name: "s-1179-VM", uuid: 
"44962385-e324-4eda-941e-526ed6fa3cab", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1179].






-----Opprinnelig melding-----
Fra: Jithin Raju <jithin.r...@shapeblue.com>
Sendt: tirsdag 18. april 2023 11:39
Til: users@cloudstack.apache.org
Emne: Re: SSVM stopped and will not be recreated.... :-(

Hi David,

>Secondary Storage shows 0.00%
SSVM should be up and running to report the capacity.

s-1178-VM: What happens when you destroy this SSVM? Does it create a new one, 
new has the same error? "no usable volumes found for the VM"

Can you follow 'secstorage-1' thread for the new SSVM creation/allocation, any 
errors observed?

-Jithin

From: David Larsen <david.lar...@adcom.no>
Date: Tuesday, 18 April 2023 at 2:15 AM
To: users@cloudstack.apache.org <users@cloudstack.apache.org>
Subject: SSVM stopped and will not be recreated.... :-( Hi


I still got his error when I deleted the SSVM in Cloudstack.
Any tips for where to begin?

In Cloudstack (4.17.2) Dashboard GUI, the Secondary Storage shows 0.00% Is this 
related to the SSVM not autocreated/starting up?
The secondary storage share is working from other nfs test clients, and I 
haven't done any changes in nfs config as I can remember. The nfs server is on 
another ubuntu machine.

The message "Unable to create deployment, no usable volumes found for the VM: 
1178" is about the SSVM s-1178-VM....
Is it my vmware volumes that are suddenly not useable. They are only 36% in use.

I'm a bit lost here...

Cloudstack 4.17.2 on ububtu 18.04
Mysql 8 on ubuntu 18.04
Nfs on ubuntu 20.04


Thanks

2023-04-17 22:10:55,250 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-28:ctx-d1c08244 job-12251/job-12279 ctx-cdc0e682) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:10:55,251 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-28:ctx-d1c08244 job-12251/job-12279 ctx-cdc0e682) 
(logid:c33fffa8) Successfully transitioned to start state for VM instance {id: 
"1178", name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} reservation id = 1e067ee8-0cee-45f1-9b79-7a39386ce59e
2023-04-17 22:10:55,413 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-28:ctx-d1c08244 job-12251/job-12279 ctx-cdc0e682) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:10:55,415 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-28:ctx-d1c08244 job-12251/job-12279 ctx-cdc0e682) 
(logid:c33fffa8) Unable to orchestrate start VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1178].
2023-04-17 22:10:55,510 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-d7186962) (logid:45fa25f1) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-17 22:11:23,658 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-4ca33b80) (logid:de33d41d) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-17 22:11:25,242 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-29:ctx-fa5f251f job-12251/job-12280 ctx-f728683a) 
(logid:c33fffa8) orchestrating VM start for 's-1178-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d<mailto:com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d>
 set to null
2023-04-17 22:11:25,252 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-29:ctx-fa5f251f job-12251/job-12280 ctx-f728683a) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:11:25,253 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-29:ctx-fa5f251f job-12251/job-12280 ctx-f728683a) 
(logid:c33fffa8) Successfully transitioned to start state for VM instance {id: 
"1178", name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} reservation id = df3613bb-90e0-4ae1-9d39-a3988d504470
2023-04-17 22:11:25,479 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-29:ctx-fa5f251f job-12251/job-12280 ctx-f728683a) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:11:25,482 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-29:ctx-fa5f251f job-12251/job-12280 ctx-f728683a) 
(logid:c33fffa8) Unable to orchestrate start VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1178].
2023-04-17 22:11:25,582 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-4ca33b80) (logid:de33d41d) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-17 22:11:53,650 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-9a6c6228) (logid:c999aa9a) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-17 22:11:55,229 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-30:ctx-41c993b7 job-12251/job-12281 ctx-1547297e) 
(logid:c33fffa8) orchestrating VM start for 's-1178-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d<mailto:com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d>
 set to null
2023-04-17 22:11:55,239 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-30:ctx-41c993b7 job-12251/job-12281 ctx-1547297e) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:11:55,239 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-30:ctx-41c993b7 job-12251/job-12281 ctx-1547297e) 
(logid:c33fffa8) Successfully transitioned to start state for VM instance {id: 
"1178", name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} reservation id = 2deb31f7-910d-412c-916c-c0dc54df5f9a
2023-04-17 22:11:55,399 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-30:ctx-41c993b7 job-12251/job-12281 ctx-1547297e) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:11:55,401 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-30:ctx-41c993b7 job-12251/job-12281 ctx-1547297e) 
(logid:c33fffa8) Unable to orchestrate start VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1178].
2023-04-17 22:11:55,501 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-9a6c6228) (logid:c999aa9a) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-17 22:12:23,655 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-9fe40a25) (logid:5f128a89) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-17 22:12:25,242 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-31:ctx-131c15f0 job-12251/job-12282 ctx-d0187bcc) 
(logid:c33fffa8) orchestrating VM start for 's-1178-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d<mailto:com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d>
 set to null
2023-04-17 22:12:25,250 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-31:ctx-131c15f0 job-12251/job-12282 ctx-d0187bcc) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:12:25,250 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-31:ctx-131c15f0 job-12251/job-12282 ctx-d0187bcc) 
(logid:c33fffa8) Successfully transitioned to start state for VM instance {id: 
"1178", name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} reservation id = 28c14a58-d91c-4211-8fde-199072c7018c
2023-04-17 22:12:25,415 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-31:ctx-131c15f0 job-12251/job-12282 ctx-d0187bcc) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:12:25,417 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-31:ctx-131c15f0 job-12251/job-12282 ctx-d0187bcc) 
(logid:c33fffa8) Unable to orchestrate start VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1178].
2023-04-17 22:12:25,531 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-9fe40a25) (logid:5f128a89) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-17 22:12:53,658 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-b35ae1ab) (logid:805d78e5) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-17 22:12:55,223 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-32:ctx-b75e1008 job-12251/job-12283 ctx-0ce58d43) 
(logid:c33fffa8) orchestrating VM start for 's-1178-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d<mailto:com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d>
 set to null
2023-04-17 22:12:55,232 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-32:ctx-b75e1008 job-12251/job-12283 ctx-0ce58d43) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:12:55,232 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-32:ctx-b75e1008 job-12251/job-12283 ctx-0ce58d43) 
(logid:c33fffa8) Successfully transitioned to start state for VM instance {id: 
"1178", name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} reservation id = f144244d-75f7-45bc-b1dd-94d67749fa20
2023-04-17 22:12:55,386 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-32:ctx-b75e1008 job-12251/job-12283 ctx-0ce58d43) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:12:55,388 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-32:ctx-b75e1008 job-12251/job-12283 ctx-0ce58d43) 
(logid:c33fffa8) Unable to orchestrate start VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1178].
2023-04-17 22:12:55,495 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-b35ae1ab) (logid:805d78e5) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
2023-04-17 22:13:23,660 INFO  [o.a.c.s.SecondaryStorageManagerImpl] 
(secstorage-1:ctx-7a63db20) (logid:91af80f4) Found a stopped secondary storage 
VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"}, starting it.
2023-04-17 22:13:25,228 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-33:ctx-db5e9ae2 job-12251/job-12284 ctx-c05a2869) 
(logid:c33fffa8) orchestrating VM start for 's-1178-VM' 
com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d<mailto:com.cloud.vm.VirtualMachineProfile$Param@b66cdd7d>
 set to null
2023-04-17 22:13:25,237 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-33:ctx-db5e9ae2 job-12251/job-12284 ctx-c05a2869) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Stopped] to [Starting] with event [StartRequested]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:13:25,238 DEBUG [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-33:ctx-db5e9ae2 job-12251/job-12284 ctx-c05a2869) 
(logid:c33fffa8) Successfully transitioned to start state for VM instance {id: 
"1178", name: "s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} reservation id = b47c0d6e-3259-44aa-8fce-cb60f7c3e8df
2023-04-17 22:13:25,400 DEBUG [c.c.c.CapacityManagerImpl] 
(Work-Job-Executor-33:ctx-db5e9ae2 job-12251/job-12284 ctx-c05a2869) 
(logid:c33fffa8) VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} state 
transited from [Starting] to [Stopped] with event [OperationFailed]. VM's 
original host: null, new host: null, host before state transition: null
2023-04-17 22:13:25,402 WARN  [c.c.v.VirtualMachineManagerImpl] 
(Work-Job-Executor-33:ctx-db5e9ae2 job-12251/job-12284 ctx-c05a2869) 
(logid:c33fffa8) Unable to orchestrate start VM instance {id: "1178", name: 
"s-1178-VM", uuid: "457e6f90-8bb1-4026-b908-b555511951f6", 
type="SecondaryStorageVm"} due to [Unable to create deployment, no usable 
volumes found for the VM: 1178].
2023-04-17 22:13:25,502 WARN  [c.c.v.SystemVmLoadScanner] 
(secstorage-1:ctx-7a63db20) (logid:91af80f4) Unexpected exception Unable to 
orchestrate start VM instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].
com.cloud.utils.exception.CloudRuntimeException: Unable to orchestrate start VM 
instance {id: "1178", name: "s-1178-VM", uuid: 
"457e6f90-8bb1-4026-b908-b555511951f6", type="SecondaryStorageVm"} due to 
[Unable to create deployment, no usable volumes found for the VM: 1178].

Med vennlig hilsen

David Larsen
Senior systemkonsulent

[cid:image001.png@01D9717D.B9FEE240]
ADCOM MOLDE, IT Data AS
Fabrikkvegen 13  | 6415 Molde
Mobil: 959 48 308 | Sentralbord: 71 25 06 40 
david.lar...@adcom.no<mailto:david.lar...@adcom.no> | 
http://www.adcom.no/<http://www.adcom.no/><http://www.adcom.no/%3chttp:/www.adcom.no/%3e><http://www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e><http://www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e><http://www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3e><http://www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3e%3e><http://www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3chttp:/www.adcom.no/%3chttp:/www.adcom.no/%3e%3e%3e%3e%3e%3e>

[Milj?fyrt?rn]    [cid:image003.png@01D9717D.B9FEE240]

F?lg oss p? sosiale medier: [Facebook icon] 
<https://www.facebook.com/adcommolde/> [LinkedIn icon] 
<https://www.linkedin.com/company/10249752?trk=tyah&trkInfo=clickedVertical%3Acompany%2CclickedEntityId%3A10249752%2Cidx%3A2-1-2%2CtarId%3A1449043739552%2Ctas%3Aadcom%20molde>
P Tenk p? milj?et f?r du skriver ut denne eposten