Hey Angus,
My ACS is 4.11.2 with advanced network on KVM, config drive is enabled as
network provider.
I have done more tests, I have two ACS installations, one has Primary Storage
as Ceph RBD and the other as SharedMountPoint.
The error is for the RBD pool (see log), everything works fine for SMP.
Piotr
-----Original Message-----
From: Paul Angus <paul.an...@shapeblue.com>
Sent: Monday, February 11, 2019 9:25 AM
To: users@cloudstack.apache.org; pi...@piszki.pl
Subject: RE: L2+ConfigDrive
Hi Piotr,
Which version of CloudStack are you looking at?
And, have you checked that configdrive is enabled as a network provider?
paul.an...@shapeblue.com
www.shapeblue.com
Amadeus House, Floral Street, London WC2E 9DPUK @shapeblue
-----Original Message-----
From: Piotr Pisz <pi...@piszki.pl>
Sent: 10 February 2019 16:04
To: users@cloudstack.apache.org
Subject: L2+ConfigDrive
Hello!
I am interested in using Config Drive with the L2 network, unfortunately there
is no word in the documentation for this topic.
Has anyone used this and can guide me?
Service offering L2 + ConfigDrive does not work, it is clearly missing (?) of
the iso file.
I have an error: Unable to start VM instance.
Regards,
Piotr
2019-02-11 09:49:46,055 DEBUG [c.c.n.e.ConfigDriveNetworkElement]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Creating config drive ISO for vm: i-2-17-VM
2019-02-11 09:49:46,150 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Seq 5-6917247552664371212: Sending { Cmd , MgmtId:
345049913471, via: 5(cstack-1), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.HandleConfigDriveIsoCommand":{"isoFile":"configdrive/i-2-17-VM.iso","create":true,"destStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"01cfa0c5-32a0-37c6-bc10-f1d9e5bcd1f5","id":17,"poolType":"RBD","host":"192.168.70.71","path":"cloudstack","port":6789,"url":"RBD://192.168.70.71/cloudstack/?ROLE=Primary&STOREUUID=01cfa0c5-32a0-37c6-bc10-f1d9e5bcd1f5","isManaged":false}},"wait":0}}]
}
2019-02-11 09:49:46,380 DEBUG [c.c.a.t.Request] (AgentManager-Handler-7:null)
(logid:) Seq 5-6917247552664371212: Processing: { Ans: , MgmtId: 345049913471,
via: 5, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2019-02-11 09:49:46,380 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Seq 5-6917247552664371212: Received: { Ans: , MgmtId:
345049913471, via: 5(cstack-1), Ver: v1, Flags: 10, { Answer } }
2019-02-11 09:49:46,381 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Service SecurityGroup is not supported in the network id=208
2019-02-11 09:49:46,492 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Seq 5-6917247552664371213: Sending { Cmd , MgmtId:
345049913471, via: 5(cstack-1), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StartCommand":{"vm":{"id":17,"name":"i-2-17-VM","type":"User","cpus":1,"minSpeed":2000,"maxSpeed":2000,"minRam":268435456,"maxRam":268435456,"arch":"x86_64","os":"CentOS
7","platformEmulator":"CentOS
7","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"8zdqKN7xqjRLALvsixuCtQ","params":{"cpuNumber":"1","deployvm":"true","memory":"256","cpuSpeed":"2000","Message.ReservedCapacityFreed.Flag":"false","rootDiskController":"osdefault"},"uuid":"e0d3cc29-3de4-496e-b45f-ef0e20399d6c","disks":[{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"configdrive/i-2-17-VM.iso","uuid":"e0d3cc29-3de4-496e-b45f-ef0e20399d6c","id":0,"format":"ISO","accountId":0,"hvm":false,"imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"01cfa0c5-32a0-37c6-bc10-f1d9e5bcd1f5","id":17,"poolType":"RBD","host":"192.168.70.71","path":"cloudstack","port":6789,"url":"RBD://192.168.70.71/cloudstack/?ROLE=Primary&STOREUUID=01cfa0c5-32a0-37c6-bc10-f1d9e5bcd1f5","isManaged":false}},"bootable":false,"directDownload":false}},"diskSeq":4,"path":"configdrive/i-2-17-VM.iso","type":"ISO"},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"a27d56f4-115a-4093-9403-2c1c0afb06e7","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"01cfa0c5-32a0-37c6-bc10-f1d9e5bcd1f5","id":17,"poolType":"RBD","host":"192.168.70.71","path":"cloudstack","port":6789,"url":"RBD://192.168.70.71/cloudstack/?ROLE=Primary&STOREUUID=01cfa0c5-32a0-37c6-bc10-f1d9e5bcd1f5","isManaged":false}},"name":"ROOT-17","size":8589934592,"path":"a27d56f4-115a-4093-9403-2c1c0afb06e7","volumeId":71,"vmName":"i-2-17-VM","accountId":2,"format":"RAW","provisioningType":"THIN","id":71,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"KVM"}},"diskSeq":0,"path":"a27d56f4-115a-4093-9403-2c1c0afb06e7","type":"ROOT","_details":{"storageHost":"192.168.70.71","managed":"false","storagePort":"6789","volumeSize":"8589934592"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false,"bootable":false,"directDownload":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"pxeDisable":false,"nicUuid":"dfa69fe9-ad1e-4eb8-a769-164182097585","details":{"PromiscuousMode":"false","ForgedTransmits":"true","MacAddressChanges":"true"},"uuid":"5e4a8af7-9e79-45dc-88f3-0f57954adef9","mac":"02:00:5a:47:00:02","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://32","isolationUri":"vlan://32","isSecurityGroupEnabled":false,"name":"cloudbr2"}],"vmData":[["metadata","service-offering","Custom-No-HA-RBD"],["metadata","availability-zone","Piszki
Lab"],["metadata","local-hostname","CD-1"],["metadata","local-ipv4",null],["metadata","public-ipv4",null],["metadata","public-hostname",null],["metadata","instance-id","e0d3cc29-3de4-496e-b45f-ef0e20399d6c"],["metadata","vm-id","e0d3cc29-3de4-496e-b45f-ef0e20399d6c"],["metadata","public-keys",null],["metadata","cloud-identifier","CloudStack-{3604e1ce-bf46-4644-8c33-55c688b95cca}"]],"configDriveLabel":"config-2","guestOsDetails":{}},"hostIp":"192.168.70.70","executeInSequence":false,"wait":0}}]
}
2019-02-11 09:49:46,943 DEBUG [c.c.a.ApiServlet]
(qtp2017354584-12:ctx-04423aa2) (logid:7f5c9dd7) ===START=== 192.168.0.35 --
GET
command=queryAsyncJobResult&jobId=8cbf7dac-7f6e-4dd5-91cb-99140192332b&response=json&_=1549874985160
2019-02-11 09:49:46,964 DEBUG [c.c.a.ApiServer] (qtp2017354584-12:ctx-04423aa2
ctx-be101738) (logid:7f5c9dd7) CIDRs from which account
'Acct[c96785bb-25fe-11e9-9d50-42e89c46c342-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2019-02-11 09:49:47,009 DEBUG [c.c.a.ApiServlet] (qtp2017354584-12:ctx-04423aa2
ctx-be101738) (logid:7f5c9dd7) ===END=== 192.168.0.35 -- GET
command=queryAsyncJobResult&jobId=8cbf7dac-7f6e-4dd5-91cb-99140192332b&response=json&_=1549874985160
2019-02-11 09:49:47,140 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-9:null) (logid:) SeqA 20-99814: Processing Seq 20-99814:
{ Cmd , MgmtId: -1, via: 20, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":5,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2019-02-11 09:49:47,200 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-9:null) (logid:) SeqA 20-99814: Sending Seq 20-99814: {
Ans: , MgmtId: 345049913471, via: 20, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2019-02-11 09:49:47,571 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) recalculating system capacity
2019-02-11 09:49:47,571 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Executing cpu/ram capacity update
2019-02-11 09:49:47,576 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) Found 3 VMs on host 5
2019-02-11 09:49:47,582 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) Found 0 VM, not running on host 5
2019-02-11 09:49:47,584 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) Calibrate used cpu core for host: 5 old usedCpuCore:2 new usedCpuCore:3
2019-02-11 09:49:47,594 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) No need to calibrate cpu capacity, host:5 usedCpu: 3000 reservedCpu: 0
2019-02-11 09:49:47,595 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) No need to calibrate memory capacity, host:5 usedMem: 1879048192
reservedMem: 0
2019-02-11 09:49:47,615 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) Found 1 VMs on host 14
2019-02-11 09:49:47,632 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) Found 2 VM, not running on host 14
2019-02-11 09:49:47,646 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) No need to calibrate cpu capacity, host:14 usedCpuCore: 1
reservedCpuCore: 0
2019-02-11 09:49:47,646 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) No need to calibrate cpu capacity, host:14 usedCpu: 500 reservedCpu: 0
2019-02-11 09:49:47,646 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) No need to calibrate memory capacity, host:14 usedMem: 268435456
reservedMem: 0
2019-02-11 09:49:47,663 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) Found 1 VMs on host 17
2019-02-11 09:49:47,681 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) Found 3 VM, not running on host 17
2019-02-11 09:49:47,707 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) No need to calibrate cpu capacity, host:17 usedCpuCore: 1
reservedCpuCore: 0
2019-02-11 09:49:47,707 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) No need to calibrate cpu capacity, host:17 usedCpu: 2000 reservedCpu: 0
2019-02-11 09:49:47,707 DEBUG [c.c.c.CapacityManagerImpl] (Thread-26:null)
(logid:) No need to calibrate memory capacity, host:17 usedMem: 536870912
reservedMem: 0
2019-02-11 09:49:47,734 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Done executing cpu/ram capacity update
2019-02-11 09:49:47,734 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Executing storage capacity update
2019-02-11 09:49:47,753 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Found storage pool Primary-CFS of type SharedMountPoint
2019-02-11 09:49:47,753 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Total over provisioned capacity of the pool Primary-CFS id: 5 is
188173254656
2019-02-11 09:49:47,758 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Successfully set Capacity - 188173254656 for capacity type - 3 ,
DataCenterId - 5, HostOrPoolId - 5, PodId 5
2019-02-11 09:49:47,765 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Found storage pool Primary-NFS of type NetworkFilesystem with
overprovisioning factor 2
2019-02-11 09:49:47,765 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Total over provisioned capacity calculated is 2 * 2948732551168
2019-02-11 09:49:47,765 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Total over provisioned capacity of the pool Primary-NFS id: 14 is
5897465102336
2019-02-11 09:49:47,766 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Successfully set Capacity - 5897465102336 for capacity type - 3 ,
DataCenterId - 5, HostOrPoolId - 14, PodId 5
2019-02-11 09:49:47,774 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Found storage pool Primary-RBD of type RBD with overprovisioning
factor 2
2019-02-11 09:49:47,774 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Total over provisioned capacity calculated is 2 * 483146072064
2019-02-11 09:49:47,774 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Total over provisioned capacity of the pool Primary-RBD id: 17 is
966292144128
2019-02-11 09:49:47,792 DEBUG [c.c.s.StorageManagerImpl] (Thread-26:null)
(logid:) Successfully set Capacity - 966292144128 for capacity type - 3 ,
DataCenterId - 5, HostOrPoolId - 17, PodId 5
2019-02-11 09:49:47,792 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Done executing storage capacity update
2019-02-11 09:49:47,792 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Executing capacity updates for public ip and Vlans
2019-02-11 09:49:47,905 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Done capacity updates for public ip and Vlans
2019-02-11 09:49:47,905 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Executing capacity updates for private ip
2019-02-11 09:49:47,934 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Done executing capacity updates for private ip
2019-02-11 09:49:47,934 DEBUG [c.c.a.AlertManagerImpl] (Thread-26:null)
(logid:) Done recalculating system capacity
2019-02-11 09:49:48,415 DEBUG [c.c.a.t.Request] (AgentManager-Handler-8:null)
(logid:) Seq 5-6917247552664371213: Processing: { Ans: , MgmtId: 345049913471,
via: 5, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:268)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.createVbd(LibvirtComputingResource.java:2256)\n\tat
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtStartCommandWrapper.execute(LibvirtStartCommandWrapper.java:83)\n\tat
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtStartCommandWrapper.execute(LibvirtStartCommandWrapper.java:47)\n\tat
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1450)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:645)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1083)\n\tat
com.cloud.utils.nio.Task.call(Task.java:83)\n\tat
com.cloud.utils.nio.Task.call(Task.java:29)\n\tat
java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat
java.lang.Thread.run(Thread.java:748)\n","wait":0}}] }
2019-02-11 09:49:48,416 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Seq 5-6917247552664371213: Received: { Ans: , MgmtId:
345049913471, via: 5(cstack-1), Ver: v1, Flags: 10, { Answer } }
2019-02-11 09:49:48,441 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Cleaning up resources for the vm VM[User|i-2-17-VM] in
Starting state
2019-02-11 09:49:48,471 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Seq 5-6917247552664371214: Sending { Cmd , MgmtId:
345049913471, via: 5(cstack-1), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"checkBeforeCleanup":false,"forceStop":false,"volumesToDisconnect":[],"vmName":"i-2-17-VM","executeInSequence":false,"wait":0}}]
}
2019-02-11 09:49:49,608 DEBUG [c.c.a.t.Request] (AgentManager-Handler-10:null)
(logid:) Seq 5-6917247552664371214: Processing: { Ans: , MgmtId: 345049913471,
via: 5, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2019-02-11 09:49:49,609 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Seq 5-6917247552664371214: Received: { Ans: , MgmtId:
345049913471, via: 5(cstack-1), Ver: v1, Flags: 10, { StopAnswer } }
2019-02-11 09:49:49,633 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Service SecurityGroup is not supported in the network id=208
2019-02-11 09:49:49,675 DEBUG [c.c.n.e.ConfigDriveNetworkElement]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Deleting config drive ISO for vm: i-2-17-VM
2019-02-11 09:49:49,692 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Seq 5-6917247552664371215: Sending { Cmd , MgmtId:
345049913471, via: 5(cstack-1), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.HandleConfigDriveIsoCommand":{"isoFile":"configdrive/i-2-17-VM.iso","create":false,"destStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"01cfa0c5-32a0-37c6-bc10-f1d9e5bcd1f5","id":17,"poolType":"RBD","host":"192.168.70.71","path":"cloudstack","port":6789,"url":"RBD://192.168.70.71/cloudstack/?ROLE=Primary&STOREUUID=01cfa0c5-32a0-37c6-bc10-f1d9e5bcd1f5","isManaged":false}},"wait":0}}]
}
2019-02-11 09:49:49,762 DEBUG [c.c.a.t.Request] (AgentManager-Handler-11:null)
(logid:) Seq 5-6917247552664371215: Processing: { Ans: , MgmtId: 345049913471,
via: 5, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
2019-02-11 09:49:49,763 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Seq 5-6917247552664371215: Received: { Ans: , MgmtId:
345049913471, via: 5(cstack-1), Ver: v1, Flags: 10, { Answer } }
2019-02-11 09:49:49,763 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Successfully released network resources for the vm
VM[User|i-2-17-VM]
2019-02-11 09:49:49,763 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Successfully cleanued up resources for the vm
VM[User|i-2-17-VM] in Starting state
2019-02-11 09:49:49,794 ERROR [o.a.c.m.r.RabbitMQEventBus]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Failed to create a connection to AMQP server due to Connection
refused (Connection refused)
2019-02-11 09:49:49,794 WARN [c.c.v.UserVmStateListener]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Failed to publish state change event on the the event bus.
2019-02-11 09:49:49,844 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) VM state transitted from :Starting to Stopped with event:
OperationFailedvm's original host id: null new host id: null host id before
state transition: 5
2019-02-11 09:49:49,893 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Hosts's actual total CPU: 7006 and CPU after applying
overprovisioning: 7006
2019-02-11 09:49:49,893 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Hosts's actual total RAM: 5219319808 and RAM after applying
overprovisioning: 5219319808
2019-02-11 09:49:49,893 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) release cpu from host: 5, old used: 3000,reserved: 0, actual
total: 7006, total with overprovisioning: 7006; new used: 1000,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2019-02-11 09:49:49,893 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) release mem from host: 5, old used: 1879048192,reserved: 0,
total: 5219319808; new used: 1610612736,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2019-02-11 09:49:49,947 DEBUG [c.c.a.ApiServlet]
(qtp2017354584-15:ctx-e5cc2ff5) (logid:fad17e38) ===START=== 192.168.0.35 --
GET
command=queryAsyncJobResult&jobId=8cbf7dac-7f6e-4dd5-91cb-99140192332b&response=json&_=1549874988167
2019-02-11 09:49:49,974 DEBUG [c.c.a.ApiServer] (qtp2017354584-15:ctx-e5cc2ff5
ctx-25d1ac00) (logid:fad17e38) CIDRs from which account
'Acct[c96785bb-25fe-11e9-9d50-42e89c46c342-admin]' is allowed to perform API
calls: 0.0.0.0/0,::/0
2019-02-11 09:49:50,034 ERROR [o.a.c.m.r.RabbitMQEventBus]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Failed to create a connection to AMQP server due to Connection
refused (Connection refused)
2019-02-11 09:49:50,034 WARN [c.c.v.UserVmStateListener]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Failed to publish state change event on the the event bus.
2019-02-11 09:49:50,037 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Caught CloudRuntimeException, returning job failed
com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is
of class com.cloud.agent.api.StartAnswer
2019-02-11 09:49:50,041 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683 ctx-bd7e2a24)
(logid:8cbf7dac) Done executing VM work job:
com.cloud.vm.VmWorkStart{"dcId":0,"rawParams":{"VmPassword":"rO0ABXQADnNhdmVkX3Bhc3N3b3Jk"},"userId":2,"accountId":2,"vmId":17,"handlerName":"VirtualMachineManagerImpl"}
2019-02-11 09:49:50,143 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-2:ctx-58d87bcf job-677/job-683) (logid:8cbf7dac) Done with
run of VM work job: com.cloud.vm.VmWorkStart for VM 17, job origin: 677
2019-02-11 09:49:50,155 DEBUG [c.c.a.ApiServlet] (qtp2017354584-15:ctx-e5cc2ff5
ctx-25d1ac00) (logid:fad17e38) ===END=== 192.168.0.35 -- GET
command=queryAsyncJobResult&jobId=8cbf7dac-7f6e-4dd5-91cb-99140192332b&response=json&_=1549874988167
2019-02-11 09:49:50,217 DEBUG [c.c.v.UserVmManagerImpl]
(API-Job-Executor-1:ctx-2ed3091f job-677 ctx-aa636158) (logid:8cbf7dac)
Destroying vm VM[User|i-2-17-VM] as it failed to create on Host with Id:null
2019-02-11 09:49:50,684 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-1:ctx-2ed3091f job-677) (logid:8cbf7dac) Unexpected exception
while executing org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin
com.cloud.utils.exception.CloudRuntimeException: Unable to start VM instance
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4942)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5100)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:581)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:529)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
