cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From William Hutchins <whutch...@correct.com.au>
Subject RE: ACS 4.9 System VMs Failing to Start
Date Wed, 30 Nov 2016 09:57:40 GMT
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:Dag.Sonstebo@shapeblue.com] 
Sent: Wednesday, 30 November 2016 6:39 PM
To: users@cloudstack.apache.org
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" <whutchins@correct.com.au> 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&from=whutchins@correct.com.au
    
    
    


Dag.Sonstebo@shapeblue.com
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&from=whutchins@correct.com.au


Mime
View raw message