As per log your host doesn't enough capacity. Deployment allocation algorithm fail to find the cluster having enough capacity to deploy a vm.
Can you check your host capacity in dash board and host status in the host table or in UI(Infrastructure-Hosts] . Regards Sadhu -----Original Message----- From: CK [mailto:cloudw...@gmail.com] Sent: 14 March 2013 15:53 To: cloudstack-users@incubator.apache.org Subject: Unable to start Instance I am trying to create my first instance and I get the following error message: "Unable to create a deployment for VM[User|d8f24525-fce2-488e-8d76-95d4ade93235]" Here is the extract from the cloud-management log, can someone help identify what the problem is: Thanks, 2013-03-14 10:12:16,724 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-12:null) Seq 1-623509510: Response Received: 2013-03-14 10:12:16,725 DEBUG [agent.transport.Request] (DirectAgent-12:null) Seq 1-623509510: Processing: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] } 2013-03-14 10:12:16,725 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-1:null) Seq 1-623509510: Executing request 2013-03-14 10:12:17,063 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-27:null) Ping from 1 2013-03-14 10:12:17,112 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-1:null) Seq 1-623509510: Response Received: 2013-03-14 10:12:17,112 DEBUG [agent.transport.Request] (DirectAgent-1:null) Seq 1-623509510: Processing: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] } 2013-03-14 10:12:17,113 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-5:null) Seq 1-623509510: Executing request 2013-03-14 10:12:17,392 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 4-7: Processing Seq 4-7: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"192.168.2.205\",\n \"port\": 5901,\n \"tag\": \"f674245e-5d07-4190-aaf6-6768053873a2\",\n \"createTime\": 1363255937191,\n \"lastUsedTime\": 1363255937191\n }\n ]\n}","wait":0}}] } 2013-03-14 10:12:17,400 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 4-7: Sending Seq 4-7: { Ans: , MgmtId: 52232380435, via: 4, Ver: v1, Flags: 100010, [{"AgentControlAnswer":{"result":true,"wait":0}}] } 2013-03-14 10:12:17,527 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-5:null) Seq 1-623509510: Response Received: 2013-03-14 10:12:17,528 DEBUG [agent.transport.Request] (DirectAgent-5:null) Seq 1-623509510: Processing: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] } 2013-03-14 10:12:17,619 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-20:null) Ping from 1 2013-03-14 10:12:18,108 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-20:null) Ping from 1 2013-03-14 10:12:19,516 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-20:null) Ping from 1 2013-03-14 10:12:22,870 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-33:null) Seq 1-623509510: Executing request 2013-03-14 10:12:23,165 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-33:null) Seq 1-623509510: Response Received: 2013-03-14 10:12:23,166 DEBUG [agent.transport.Request] (DirectAgent-33:null) Seq 1-623509510: Processing: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] } 2013-03-14 10:12:37,195 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-15:null) Ping from 3 2013-03-14 10:12:45,010 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-12:null) Access granted to Acct[2-admin] to Domain:1/ by DomainChecker 2013-03-14 10:12:51,212 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-9:null) Allocating in the DB for vm 2013-03-14 10:12:51,213 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-9:null) Allocating entries for VM: VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] 2013-03-14 10:12:51,219 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-9:null) Allocating nics for VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] 2013-03-14 10:12:51,221 DEBUG [cloud.network.NetworkManagerImpl] (catalina-exec-9:null) Allocating nic for vm VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] in network Ntwk[204|Guest|6] with requested profile NicProfile[0-0-null-null-null 2013-03-14 10:12:51,233 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-9:null) Allocaing disks for VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] 2013-03-14 10:12:51,266 DEBUG [cloud.vm.VirtualMachineManagerImpl] (catalina-exec-9:null) Allocation completed for VM: VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] 2013-03-14 10:12:51,267 DEBUG [cloud.vm.UserVmManagerImpl] (catalina-exec-9:null) Successfully allocated DB entry for VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] 2013-03-14 10:12:51,388 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-9:null) submit async job-17, job: AsyncJobVO {id:17, userId: 2, accountId: 2, sessionKey: null, instanceType: null, instanceId: 8, cmd: com.cloud.api.commands.DeployVMCmd, cmdOriginator: null, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 52232380435, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} 2013-03-14 10:12:51,399 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-1:job-17) Executing com.cloud.api.commands.DeployVMCmd for job-17 2013-03-14 10:12:51,512 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-17) 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 2013-03-14 10:12:51,512 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-17) Successfully transitioned to start state for VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] reservation id = e5575ba7-5c0a-46d4-9ecb-3f88208abcb3 2013-03-14 10:12:51,519 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-17) Trying to deploy VM, vm has dcId: 1 and podId: null 2013-03-14 10:12:51,519 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-1:job-17) Deploy avoids pods: null, clusters: null, hosts: null 2013-03-14 10:12:51,524 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-17) DeploymentPlanner allocation algorithm: random 2013-03-14 10:12:51,524 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-17) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 500, requested ram: 536870912 2013-03-14 10:12:51,524 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-17) Is ROOT volume READY (pool already allocated)?: No 2013-03-14 10:12:51,524 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-17) Searching all possible resources under this Zone: 1 2013-03-14 10:12:51,527 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-17) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Zone: 1 2013-03-14 10:12:51,529 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-17) CPUOverprovisioningFactor considered: 1.0 2013-03-14 10:12:51,532 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-1:job-17) No clusters found having a host with enough capacity, returning. 2013-03-14 10:12:51,542 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-17) 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 2013-03-14 10:12:51,552 DEBUG [cloud.vm.UserVmManagerImpl] (Job-Executor-1:job-17) Destroying vm VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] as it failed to create 2013-03-14 10:12:51,565 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-1:job-17) VM state transitted from :Stopped to Error with event: OperationFailedToErrorvm's original host id: null new host id: null host id before state transition: null 2013-03-14 10:12:51,668 INFO [api.commands.DeployVMCmd] (Job-Executor-1:job-17) com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[User|d8f24525-fce2-488e-8d76-95d4ade93235]Scope=interface com.cloud.dc.DataCenter; id=1 2013-03-14 10:12:51,669 WARN [cloud.api.ApiDispatcher] (Job-Executor-1:job-17) class com.cloud.api.ServerApiException : Unable to create a deployment for VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] 2013-03-14 10:12:51,670 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-1:job-17) Complete async job-17, jobStatus: 2, resultCode: 530, result: Error Code: 533 Error text: Unable to create a deployment for VM[User|d8f24525-fce2-488e-8d76-95d4ade93235] 2013-03-14 10:12:56,430 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-10:null) Async job-17 completed 2013-03-14 10:13:12,319 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-1:null) Ping from 4 2013-03-14 10:13:19,426 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-33:null) Ping from 1 2013-03-14 10:13:22,870 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-16:null) Seq 1-623509510: Executing request 2013-03-14 10:13:23,157 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-16:null) Seq 1-623509510: Response Received: 2013-03-14 10:13:23,158 DEBUG [agent.transport.Request] (DirectAgent-16:null) Seq 1-623509510: Processing: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] } 2013-03-14 10:13:37,205 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:null) Ping from 3 2013-03-14 10:14:09,758 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 removed accounts to cleanup 2013-03-14 10:14:09,761 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled accounts to cleanup 2013-03-14 10:14:09,764 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 inactive domains to cleanup 2013-03-14 10:14:09,769 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled projects to cleanup 2013-03-14 10:14:09,783 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 removed accounts to cleanup 2013-03-14 10:14:09,788 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled accounts to cleanup 2013-03-14 10:14:09,792 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 inactive domains to cleanup 2013-03-14 10:14:09,798 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled projects to cleanup 2013-03-14 10:14:09,808 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 removed accounts to cleanup 2013-03-14 10:14:09,815 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled accounts to cleanup 2013-03-14 10:14:09,818 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 inactive domains to cleanup 2013-03-14 10:14:09,826 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled projects to cleanup 2013-03-14 10:14:09,835 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 removed accounts to cleanup 2013-03-14 10:14:09,839 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled accounts to cleanup 2013-03-14 10:14:09,844 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 inactive domains to cleanup 2013-03-14 10:14:09,850 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled projects to cleanup 2013-03-14 10:14:09,863 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 removed accounts to cleanup 2013-03-14 10:14:09,871 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled accounts to cleanup 2013-03-14 10:14:09,876 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 inactive domains to cleanup 2013-03-14 10:14:09,883 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled projects to cleanup 2013-03-14 10:14:09,894 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 removed accounts to cleanup 2013-03-14 10:14:09,900 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled accounts to cleanup 2013-03-14 10:14:09,904 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 inactive domains to cleanup 2013-03-14 10:14:09,907 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled projects to cleanup 2013-03-14 10:14:10,101 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,106 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,108 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,116 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,128 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,131 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,135 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,139 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,148 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,150 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,155 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,169 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,178 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,183 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,192 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,199 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,208 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,213 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,221 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,223 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:10,230 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:10,234 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:12,323 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-3:null) Ping from 4 2013-03-14 10:14:19,458 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-36:null) Ping from 1 2013-03-14 10:14:22,870 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-37:null) Seq 1-623509510: Executing request 2013-03-14 10:14:23,139 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-37:null) Seq 1-623509510: Response Received: 2013-03-14 10:14:23,139 DEBUG [agent.transport.Request] (DirectAgent-37:null) Seq 1-623509510: Processing: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] } 2013-03-14 10:14:23,360 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) VmStatsCollector is running... 2013-03-14 10:14:23,360 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) StorageCollector is running... 2013-03-14 10:14:23,360 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) HostStatsCollector is running... 2013-03-14 10:14:23,382 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-40:null) Seq 1-623509525: Executing request 2013-03-14 10:14:23,444 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 3-1354235914: Received: { Ans: , MgmtId: 52232380435, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-03-14 10:14:23,453 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-8:null) Seq 1-623509526: Executing request 2013-03-14 10:14:23,648 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-40:null) Seq 1-623509525: Response Received: 2013-03-14 10:14:23,648 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-623509525: Received: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } } 2013-03-14 10:14:23,847 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-8:null) Seq 1-623509526: Response Received: 2013-03-14 10:14:23,848 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-623509526: Received: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-03-14 10:14:37,168 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-5:null) Ping from 3 2013-03-14 10:14:38,040 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:14:38,043 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:14:38,819 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:38,849 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:38,877 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:38,923 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:38,993 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:39,092 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,094 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:39,182 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:39,183 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,234 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:39,235 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,288 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,291 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:39,330 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,353 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:39,378 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,403 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:14:39,417 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,452 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,486 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,514 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:14:39,555 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:15:06,750 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-03-14 10:15:06,975 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-03-14 10:15:07,697 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 removed accounts to cleanup 2013-03-14 10:15:07,700 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled accounts to cleanup 2013-03-14 10:15:07,702 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 inactive domains to cleanup 2013-03-14 10:15:07,703 INFO [cloud.user.AccountManagerImpl] (AccountChecker-1:null) Found 0 disabled projects to cleanup 2013-03-14 10:15:08,043 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 2013-03-14 10:15:08,048 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 2013-03-14 10:15:08,276 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,278 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,280 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,282 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,284 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,286 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,288 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,289 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,291 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,293 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,295 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,297 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,299 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,300 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,302 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,303 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,305 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,307 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,309 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,310 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,312 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,314 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:08,315 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Deleting events older than: Wed Feb 27 10:15:08 GMT 2013 2013-03-14 10:15:08,317 DEBUG [cloud.server.ManagementServerImpl] (EventChecker-1:null) Found 0 events to be purged 2013-03-14 10:15:09,807 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Snapshot scheduler.poll is being called at 2013-03-14 10:15:09 GMT 2013-03-14 10:15:09,809 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Got 0 snapshots to be executed at 2013-03-14 10:15:09 GMT 2013-03-14 10:15:10,036 DEBUG [cloud.network.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:null) External devices stats collector is running... 2013-03-14 10:15:10,046 DEBUG [cloud.network.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:null) External devices stats collector is running... 2013-03-14 10:15:10,094 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers. 2013-03-14 10:15:10,097 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers. 2013-03-14 10:15:12,330 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null) Ping from 4 2013-03-14 10:15:19,418 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-18:null) Ping from 1 2013-03-14 10:15:22,869 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-18:null) Seq 1-623509510: Executing request 2013-03-14 10:15:23,160 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-18:null) Seq 1-623509510: Response Received: 2013-03-14 10:15:23,161 DEBUG [agent.transport.Request] (DirectAgent-18:null) Seq 1-623509510: Processing: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, [{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] } 2013-03-14 10:15:23,366 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running... 2013-03-14 10:15:23,650 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) HostStatsCollector is running... 2013-03-14 10:15:23,670 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-41:null) Seq 1-623509527: Executing request 2013-03-14 10:15:23,848 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running... 2013-03-14 10:15:23,921 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 3-1354235915: Received: { Ans: , MgmtId: 52232380435, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-03-14 10:15:23,927 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-41:null) Seq 1-623509527: Response Received: 2013-03-14 10:15:23,928 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-623509527: Received: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } } 2013-03-14 10:15:23,930 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-16:null) Seq 1-623509528: Executing request 2013-03-14 10:15:24,319 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-16:null) Seq 1-623509528: Response Received: 2013-03-14 10:15:24,319 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-623509528: Received: { Ans: , MgmtId: 52232380435, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }