CK, Make sure that your GHz on the offering on the CPU is not greater than the CPU speed on the systems. but Suresh is right, something is saying that there is a capacity allocation issue.
Thank you, Matt On Mar 14, 2013, at 6:35 AM, "Suresh Sadhu" <suresh.sa...@citrix.com<mailto:suresh.sa...@citrix.com>> wrote: 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<mailto: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 } }
