Hi Dag,
Thanks for the response.
It’s the null responses for podId and clusterId that are puzzling me, as the
pod/zone settings are taken from the current template as prescribed in the
setup documentation.
I have seen the lines that suggest a possible nfs issue, however I've been able
to verify nfs mounts are working correctly:
2016-11-30 20:46:03,426 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) No clusters found having a host with enough capacity,
returning.
2016-11-30 20:46:03,441 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) VM state transitted from :Starting to Stopped with event:
OperationFailedvm's original host id: null new host id: null host id before
state transition: null
2016-11-30 20:46:03,442 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Invocation exception, caused by:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[ConsoleProxy|v-444-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
I can't help but think the issue causing null references are an indicator of
the underlying issue.
"Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null,
requested cpu: 500, requested ram: 1073741824"
As I mentioned, I'm running Centos 6.8 having followed the documentation
available. To double check this I've run up two clean instances and running
into an identical issue each time. I've also attempted to recreate the
database, which results in the same issue. The host has an abundance of memory
and primary/secondary storage allocation - as I mentioned, NFS seems to be
running ok.
Thanks for your help, hope something jumps out!
Full log excerpt:
2016-11-30 20:46:01,561 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Zone 1 is ready to launch
console proxy
2016-11-30 20:46:01,561 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Expand console proxy standby
capacity for zone zone1
2016-11-30 20:46:01,562 INFO [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) No stopped console proxy is
available, need to allocate a new console proxy
2016-11-30 20:46:01,562 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Assign console proxy from a
newly started instance for request from data center : 1
2016-11-30 20:46:01,590 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Found existing network
configuration for offering [Network Offering
[6-Guest-DefaultSharedNetworkOfferingWithSGService]: Ntwk[204|Guest|6]
2016-11-30 20:46:01,590 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Releasing lock for
Acct[761b9b9a-b5b3-11e6-b2e6-00505610177c-system]
2016-11-30 20:46:01,591 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Found existing network
configuration for offering [Network Offering
[3-Control-System-Control-Network]: Ntwk[202|Control|3]
2016-11-30 20:46:01,591 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Releasing lock for
Acct[761b9b9a-b5b3-11e6-b2e6-00505610177c-system]
2016-11-30 20:46:01,593 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Found existing network
configuration for offering [Network Offering
[2-Management-System-Management-Network]: Ntwk[201|Management|2]
2016-11-30 20:46:01,593 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Releasing lock for
Acct[761b9b9a-b5b3-11e6-b2e6-00505610177c-system]
2016-11-30 20:46:01,605 DEBUG [c.c.v.VirtualMachineManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Allocating entries for VM:
VM[ConsoleProxy|v-444-VM]
2016-11-30 20:46:01,610 DEBUG [c.c.v.VirtualMachineManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Allocating nics for
VM[ConsoleProxy|v-444-VM]
2016-11-30 20:46:01,610 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Allocating nic for vm
VM[ConsoleProxy|v-444-VM] in network Ntwk[204|Guest|6] with requested profile
NicProfile[0-0-null-null-null
2016-11-30 20:46:01,615 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Allocating nic for vm
VM[ConsoleProxy|v-444-VM] in network Ntwk[202|Control|3] with requested profile
null
2016-11-30 20:46:01,618 DEBUG [o.a.c.e.o.NetworkOrchestrator]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Allocating nic for vm
VM[ConsoleProxy|v-444-VM] in network Ntwk[201|Management|2] with requested
profile null
2016-11-30 20:46:01,621 DEBUG [c.c.v.VirtualMachineManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Allocating disks for
VM[ConsoleProxy|v-444-VM]
2016-11-30 20:46:01,647 DEBUG [c.c.v.VirtualMachineManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Allocation completed for VM:
VM[ConsoleProxy|v-444-VM]
2016-11-30 20:46:01,649 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) received console proxy alert
2016-11-30 20:46:01,649 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) New console proxy created, zone:
zone1, proxy: v-444-VM, public IP: null, private IP: null
2016-11-30 20:46:01,656 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Sync job-1343 execution on
object VmWorkJobQueue.444
2016-11-30 20:46:01,864 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-43341f81) (logid:4ea5e8c1) Zone 1 is ready to launch
secondary storage VM
2016-11-30 20:46:03,390 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ab9dcde0) (logid:d8632fcf) Execute sync-queue
item: SyncQueueItemVO {id:1085, queueId: 1328, contentType: AsyncJob,
contentId: 1343, lastProcessMsid: 192149534251443, lastprocessNumber: 1,
lastProcessTime: Wed Nov 30 20:46:03 AEDT 2016, created: Wed Nov 30 20:46:01
AEDT 2016}
2016-11-30 20:46:03,391 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ab9dcde0) (logid:d8632fcf) Schedule queued job-1343
2016-11-30 20:46:03,401 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:68e9f239) Add
job-1343 into job monitoring
2016-11-30 20:46:03,407 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Executing
AsyncJobVO {id:1343, userId: 1, accountId: 1, instanceType: null, instanceId:
null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAABvHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 192149534251443, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Wed Nov 30 20:46:01 AEDT 2016}
2016-11-30 20:46:03,408 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Run VM
work job: com.cloud.vm.VmWorkStart for VM 444, job origin: 256
2016-11-30 20:46:03,409 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Execute VM work job:
com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":444,"handlerName":"VirtualMachineManagerImpl"}
2016-11-30 20:46:03,413 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) VM state transitted from :Stopped to Starting with event:
StartRequestedvm's original host id: null new host id: null host id before
state transition: null
2016-11-30 20:46:03,414 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Successfully transitioned to start state for
VM[ConsoleProxy|v-444-VM] reservation id = c899d0cb-3cc2-41f9-9d6c-1cea8ce60a1a
2016-11-30 20:46:03,420 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Trying to deploy VM, vm has dcId: 1 and podId: null
2016-11-30 20:46:03,420 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Deploy avoids pods: null, clusters: null, hosts: null
2016-11-30 20:46:03,422 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Deploy avoids pods: null, clusters: null, hosts: null
2016-11-30 20:46:03,423 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) DeploymentPlanner allocation algorithm:
com.cloud.deploy.FirstFitPlanner@2018d3a6
2016-11-30 20:46:03,423 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Trying to allocate a host and storage pools from dc:1,
pod:null,cluster:null, requested cpu: 500, requested ram: 1073741824
2016-11-30 20:46:03,423 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Is ROOT volume READY (pool already allocated)?: No
2016-11-30 20:46:03,423 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Searching all possible resources under this Zone: 1
2016-11-30 20:46:03,424 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Listing clusters in order of aggregate capacity, that have
(atleast one host with) enough CPU and RAM capacity under this Zone: 1
2016-11-30 20:46:03,426 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) No clusters found having a host with enough capacity,
returning.
2016-11-30 20:46:03,441 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) VM state transitted from :Starting to Stopped with event:
OperationFailedvm's original host id: null new host id: null host id before
state transition: null
2016-11-30 20:46:03,442 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Invocation exception, caused by:
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[ConsoleProxy|v-444-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
2016-11-30 20:46:03,442 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343 ctx-b687e3f7)
(logid:0d9c9856) Rethrow exception
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[ConsoleProxy|v-444-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
2016-11-30 20:46:03,442 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Done with
run of VM work job: com.cloud.vm.VmWorkStart for VM 444, job origin: 256
2016-11-30 20:46:03,443 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Unable to
complete AsyncJobVO {id:1343, userId: 1, accountId: 1, instanceType: null,
instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAABvHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 192149534251443, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Wed Nov 30 20:46:01 AEDT 2016}, job origin:256
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[ConsoleProxy|v-444-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:957)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4592)
at sun.reflect.GeneratedMethodAccessor132.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4753)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-11-30 20:46:03,444 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Complete
async job-1343, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyADdjb20uY2xvdWQuZXhjZXB0aW9uLkluc3VmZmljaWVudFNlcnZlckNhcGFjaXR5RXhjZXB0aW9uAAAAAFZNT3ACAAFaABVhZmZpbml0eUdyb3Vwc0FwcGxpZWR4cgAxY29tLmNsb3VkLmV4Y2VwdGlvbi5JbnN1ZmZpY2llbnRDYXBhY2l0eUV4Y2VwdGlvbgAAAABWTU91AgACTAACaWR0ABBMamF2YS9sYW5nL0xvbmc7TAAFc2NvcGV0ABFMamF2YS9sYW5nL0NsYXNzO3hyACJjb20uY2xvdWQuZXhjZXB0aW9uLkNsb3VkRXhjZXB0aW9ueeiOG_HkRMcCAAJMAAtjc0Vycm9yQ29kZXQAE0xqYXZhL2xhbmcvSW50ZWdlcjtMAAZpZExpc3R0ABVMamF2YS91dGlsL0FycmF5TGlzdDt4cgATamF2YS5sYW5nLkV4Y2VwdGlvbtD9Hz4aOxzEAgAAeHIAE2phdmEubGFuZy5UaHJvd2FibGXVxjUnOXe4ywMABEwABWNhdXNldAAVTGphdmEvbGFuZy9UaHJvd2FibGU7TAANZGV0YWlsTWVzc2FnZXQAEkxqYXZhL2xhbmcvU3RyaW5nO1sACnN0YWNrVHJhY2V0AB5bTGphdmEvbGFuZy9TdGFja1RyYWNlRWxlbWVudDtMABRzdXBwcmVzc2VkRXhjZXB0aW9uc3QAEExqYXZhL3V0aWwvTGlzdDt4cHEAfgANdAA7VW5hYmxlIHRvIGNyZWF0ZSBhIGRlcGxveW1lbnQgZm9yIFZNW0NvbnNvbGVQcm94eXx2LTQ0NC1WTV11cgAeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAABRzcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAARJAApsaW5lTnVtYmVyTAAOZGVjbGFyaW5nQ2xhc3NxAH4ACkwACGZpbGVOYW1lcQB-AApMAAptZXRob2ROYW1lcQB-AAp4cAAAA710ACZjb20uY2xvdWQudm0uVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbHQAHlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwuamF2YXQAEG9yY2hlc3RyYXRlU3RhcnRzcQB-ABEAABHwcQB-ABNxAH4AFHEAfgAVc3EAfgAR_____3QAJnN1bi5yZWZsZWN0LkdlbmVyYXRlZE1ldGhvZEFjY2Vzc29yMTMycHQABmludm9rZXNxAH4AEQAAACt0AChzdW4ucmVmbGVjdC5EZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsdAAhRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbC5qYXZhcQB-ABlzcQB-ABEAAAJedAAYamF2YS5sYW5nLnJlZmxlY3QuTWV0aG9kdAALTWV0aG9kLmphdmFxAH4AGXNxAH4AEQAAAGt0ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JzcQB-ABEAABKRcQB-ABNxAH4AFHEAfgAjc3EAfgARAAAAZnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9ic3EAfgARAAACKnQAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHNxAH4AEQAAADF0AD5vcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGUkMXQAG01hbmFnZWRDb250ZXh0UnVubmFibGUuamF2YXQAA3J1bnNxAH4AEQAAADh0AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxzcQB-ABEAAABndABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgAzdAAPY2FsbFdpdGhDb250ZXh0c3EAfgARAAAANXEAfgA2cQB-ADN0AA5ydW5XaXRoQ29udGV4dHNxAH4AEQAAAC50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AL3EAfgAwc3EAfgARAAAB9nEAfgAqcQB-ACtxAH4AMHNxAH4AEQAAAdd0AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4ANHNxAH4AEQAAAQZ0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGFzay5qYXZhcQB-ADBzcQB-ABEAAAR5dAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJzcQB-ABEAAAJndAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgBFcQB-ADBzcQB-ABEAAALpdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-ADBzcgAmamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUxpc3T8DyUxteyOEAIAAUwABGxpc3RxAH4ADHhyACxqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlQ29sbGVjdGlvbhlCAIDLXvceAgABTAABY3QAFkxqYXZhL3V0aWwvQ29sbGVjdGlvbjt4cHNyABNqYXZhLnV0aWwuQXJyYXlMaXN0eIHSHZnHYZ0DAAFJAARzaXpleHAAAAAAdwQAAAAAeHEAfgBReHNyABFqYXZhLmxhbmcuSW50ZWdlchLioKT3gYc4AgABSQAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAABDvc3EAfgBQAAAAAHcEAAAAAHhzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHEAfgBTAAAAAAAAAAF2cgAXY29tLmNsb3VkLmRjLkRhdGFDZW50ZXKy8Qrrp-d4vgIAAHhwAA
2016-11-30 20:46:03,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Publish
async job-1343 complete on message bus
2016-11-30 20:46:03,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Wake up
jobs related to job-1343
2016-11-30 20:46:03,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Update db
status for job-1343
2016-11-30 20:46:03,446 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Wake up
jobs joined with job-1343 and disjoin all subjobs created from job- 1343
2016-11-30 20:46:03,457 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Done
executing com.cloud.vm.VmWorkStart for job-1343
2016-11-30 20:46:03,458 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-90:ctx-9b2f5f07 job-256/job-1343) (logid:0d9c9856) Remove
job-1343 from job monitoring
2016-11-30 20:46:03,467 WARN [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Exception while trying to start
console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[ConsoleProxy|v-444-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:957)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:4592)
at sun.reflect.GeneratedMethodAccessor132.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4753)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
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:502)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-11-30 20:46:03,467 INFO [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Unable to start console proxy vm
for standby capacity, vm id : 444, will recycle it and start a new one
2016-11-30 20:46:03,467 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) received console proxy alert
2016-11-30 20:46:03,467 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
(consoleproxy-1:ctx-ffca451d) (logid:c631773f) Console proxy creation failure,
zone: zone1
2016-11-30 20:46:03,468 WARN [o.a.c.alerts] (consoleproxy-1:ctx-ffca451d)
(logid:c631773f) alertType:: 10 // dataCenterId:: 1 // podId:: null //
clusterId:: null // message:: Console proxy creation failure. zone: zone1,
error details: null
2016-11-30 20:46:07,344 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-1bae5746) (logid:6ac96c8b) Begin cleanup expired
async-jobs
2016-11-30 20:46:07,347 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-1bae5746) (logid:6ac96c8b) End cleanup expired
async-jobs
2016-11-30 20:46:17,343 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-3672365d) (logid:3228b8bb) Begin cleanup expired
async-jobs
2016-11-30 20:46:17,346 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-3672365d) (logid:3228b8bb) End cleanup expired
async-jobs
2016-11-30 20:46:17,369 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-308ded31) (logid:b8aa94a1) Found 0 routers to update
status.
2016-11-30 20:46:17,370 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-308ded31) (logid:b8aa94a1) Found 0 VPC networks to
update Redundant State.
2016-11-30 20:46:17,371 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-308ded31) (logid:b8aa94a1) Found 0 networks to
update RvR status.
2016-11-30 20:46:17,494 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-52cc66bf) (logid:93f191d5) Found 0 routers to update
status.
2016-11-30 20:46:17,495 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-52cc66bf) (logid:93f191d5) Found 0 VPC networks to
update Redundant State.
2016-11-30 20:46:17,496 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-52cc66bf) (logid:93f191d5) Found 0 networks to
update RvR status.
2016-11-30 20:46:22,446 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl]
(Vm-Operations-Cleanup-1:ctx-f8853d61) (logid:79014cf3) Expunge completed work
job-1161
2016-11-30 20:46:22,454 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl]
(Vm-Operations-Cleanup-1:ctx-f8853d61) (logid:79014cf3) Expunge completed work
job-1162
2016-11-30 20:46:22,460 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl]
(Vm-Operations-Cleanup-1:ctx-f8853d61) (logid:79014cf3) Expunge completed work
job-1163
2016-11-30 20:46:27,343 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-7d745ef8) (logid:215d1925) Begin cleanup expired
async-jobs
2016-11-30 20:46:27,346 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-7d745ef8) (logid:215d1925) End cleanup expired
async-jobs
2016-11-30 20:46:29,178 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-2:null) (logid:) Ping from 1(srvr1.cloud.priv)
2016-11-30 20:46:29,178 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-2:null) (logid:) Process host VM state report from ping
process. host: 1
2016-11-30 20:46:29,180 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-2:null) (logid:) Process VM state report. host: 1, number
of records in report: 1
2016-11-30 20:46:29,180 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-2:null) (logid:) VM state report. host: 1, vm id: 92,
power state: PowerOn
2016-11-30 20:46:29,181 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-2:null) (logid:) VM power state does not change, skip DB
writing. vm id: 92
2016-11-30 20:46:29,183 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-2:null) (logid:) Done with process of VM state report.
host: 1
Best,
Will
William Hutchins LLB, BComp, VTSP, VCP-Cloud, TITAB Reg 41468
Correct Solutions
Website | Correct IT Blog | Newsletter | LinkedIn
-----Original Message-----
From: Dag Sonstebo [mailto:[email protected]]
Sent: Wednesday, 30 November 2016 6:39 PM
To: [email protected]
Subject: Re: ACS 4.9 System VMs Failing to Start
Hi William,
We would need a larger excerpt of your logs – this isn’t actually showing the
underlying error why the CPVM can’t start.
Anohter thing to check – did you pre-seed your system VM template?
Regards,
Dag Sonstebo
Cloud Architect
ShapeBlue
On 30/11/2016, 02:58, "William Hutchins" <[email protected]> wrote:
Hi There,
I've just completed a fresh installation of ACS 4.9 using the official
documentation for Centos and the Console Proxy system VM is failing to create
as part of the wizard driven process. With a null error in the log it's being a
little difficult to diagnose further. The management console completes its
installation and I'm able to login to the ACS GUI interface
2016-11-29 10:09:04,613 DEBUG [c.c.a.ConsoleProxyAlertAdapter]
(consoleproxy-1:ctx-616f176d) (logid:7efb41fd) Console proxy creation failure,
zone: zone1
2016-11-29 10:09:04,614 WARN [o.a.c.alerts] (consoleproxy-1:ctx-616f176d)
(logid:7efb41fd) alertType:: 10 // dataCenterId:: 1 // podId:: null //
clusterId
:: null // message::
Console proxy creation failure. zone: zone1, error details: null
When I refer to Home > Infrastructure > System VMs I can see:
"s-1-vm" Secondary Storage VM in the state of starting
"v-35-vm" Console Proxy VM in the stopped state (refuses to start with the
above error)
Any assistance in pointing me in the right direction would be greatly
appreciated.
Will
--
Email cleaned and sanitised by Correct Solutions with ExchangeDefender.
Want to know more? Call 02 8831 8200 - www.correct.com.au/ed
--
ExchangeDefender Message Security: Click below to verify authenticity
http://www.exchangedefender.com/verify.asp?id=uAU305mI025865&[email protected]
[email protected]
www.shapeblue.com
53 Chandos Place, Covent Garden, London WC2N 4HSUK @shapeblue
--
Email cleaned and sanitised by Correct Solutions with ExchangeDefender.
Want to know more? Call 02 8831 8200 - www.correct.com.au/ed
--
ExchangeDefender Message Security: Click below to verify authenticity
http://www.exchangedefender.com/verify.asp?id=uAU9x9t3023902&[email protected]
