cs 版本是4.2 
虚拟化环境 xenserver 6



shi.ll

发件人： shi.ll
发送时间： 2014-12-02 10:56
收件人： users-cn@cloudstack.apache.org
主题： 不识别二级存储，系统虚拟机无法启动

各位好，我的cs 二级存储无法识别，报下边这个异常，请帮忙分析分析。


2014-12-01 00:01:03,186 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Current Used CPU: 500 , Free CPU:26636 ,Requested CPU: 500
2014-12-01 00:01:03,186 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Current Used RAM: 1073741824 , Free RAM:14999499776 ,Requested RAM: 268435456
2014-12-01 00:01:03,186 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) CPU STATS after allocation: for host: 1, old used: 500, old reserved: 0, actual total: 27136, total with overprovisioning: 27136; new used:1000, reserved:0; requested cpu:500,alloc_from_last:false
2014-12-01 00:01:03,186 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) RAM STATS after allocation: for host: 1, old used: 1073741824, old reserved: 0, total: 16073241600; new used: 1342177280, reserved: 0; requested mem: 268435456,alloc_from_last:false
2014-12-01 00:01:03,189 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) VM is being created in podId: 1
2014-12-01 00:01:03,195 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=204 is already implemented
2014-12-01 00:01:03,196 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=201 is already implemented
2014-12-01 00:01:03,209 DEBUG [db.Transaction.Transaction] (consoleproxy-1:null) Rolling back the transaction: Time = 2 Name =  -SystemVmLoadScanner$1.run:70-Executors$RunnableAdapter.call:441-FutureTask$Sync.innerRunAndReset:317-FutureTask.runAndReset:150-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101:98-ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic:180-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:204-ThreadPoolExecutor$Worker.runTask:886-ThreadPoolExecutor$Worker.run:908-Thread.run:662; called by -Transaction.rollback:898-DataCenterIpAddressDaoImpl.takeIpAddress:59-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-DataCenterDaoImpl.allocatePrivateIpAddress:248-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-PodBasedNetworkGuru.reserve:119-NetworkManagerImpl.prepareNic:2157-NetworkManagerImpl.prepare:2127-VirtualMachineManagerImpl.advanceStart:887-VirtualMachineManagerImpl.start:578-VirtualMachineManagerImpl.start:571-ConsoleProxyManagerImpl.startProxy:556
2014-12-01 00:01:03,210 INFO  [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Insufficient capacity 
com.cloud.exception.InsufficientAddressCapacityException: Unable to get a management ip addressScope=interface com.cloud.dc.Pod; id=1
at com.cloud.network.guru.PodBasedNetworkGuru.reserve(PodBasedNetworkGuru.java:121)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2157)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2127)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:887)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2014-12-01 00:01:03,215 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Cleaning up resources for the vm VM[ConsoleProxy|v-2-VM] in Starting state
2014-12-01 00:01:03,217 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1179875397: Sending  { Cmd , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"v-2-VM","wait":0}}] }
2014-12-01 00:01:03,217 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1179875397: Executing:  { Cmd , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"v-2-VM","wait":0}}] }
2014-12-01 00:01:03,217 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-370:null) Seq 1-1179875397: Executing request
2014-12-01 00:01:03,236 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Asking VirtualRouter to prepare for Nic[80818-20208-4e4f86a1-5493-406e-bf85-d2f7222181d7-192.168.140.110]
2014-12-01 00:01:03,239 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Asking SecurityGroupProvider to prepare for Nic[80818-20208-4e4f86a1-5493-406e-bf85-d2f7222181d7-192.168.140.110]
2014-12-01 00:01:03,244 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=202 is already implemented
2014-12-01 00:01:03,256 DEBUG [db.Transaction.Transaction] (secstorage-1:null) Rolling back the transaction: Time = 3 Name =  -SystemVmLoadScanner$1.run:70-Executors$RunnableAdapter.call:441-FutureTask$Sync.innerRunAndReset:317-FutureTask.runAndReset:150-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101:98-ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic:180-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:204-ThreadPoolExecutor$Worker.runTask:886-ThreadPoolExecutor$Worker.run:908-Thread.run:662; called by -Transaction.rollback:898-Transaction.removeUpTo:841-Transaction.close:665-TransactionContextBuilder.interceptComplete:56-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:131-DataCenterDaoImpl.allocateLinkLocalIpAddress:263-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-ControlNetworkGuru.reserve:154-NetworkManagerImpl.prepareNic:2157-NetworkManagerImpl.prepare:2127-VirtualMachineManagerImpl.advanceStart:887-VirtualMachineManagerImpl.start:578
2014-12-01 00:01:03,256 INFO  [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Insufficient capacity 
com.cloud.exception.InsufficientAddressCapacityException: Insufficient link local address capacityScope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.network.guru.ControlNetworkGuru.reserve(ControlNetworkGuru.java:156)
at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2157)
at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2127)
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:887)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:267)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300)
at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123)
at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2014-12-01 00:01:03,261 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Cleaning up resources for the vm VM[SecondaryStorageVm|s-20208-VM] in Starting state
2014-12-01 00:01:03,262 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1179875398: Waiting for Seq 1179875397 Scheduling:  { Cmd , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"s-20208-VM","wait":0}}] }
2014-12-01 00:01:03,293 INFO  [xen.resource.CitrixResourceBase] (DirectAgent-370:null) VM does not exist on XenServer2353b211-58cd-4725-abf6-83d1eec5ca05
2014-12-01 00:01:03,293 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-370:null) Seq 1-1179875397: Response Received: 
2014-12-01 00:01:03,293 DEBUG [agent.transport.Request] (DirectAgent-370:null) Seq 1-1179875397: Processing:  { Ans: , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
2014-12-01 00:01:03,293 DEBUG [agent.manager.AgentAttache] (DirectAgent-370:null) Seq 1-1179875398: Sending now.  is current sequence.
2014-12-01 00:01:03,293 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-1179875397: Received:  { Ans: , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2014-12-01 00:01:03,294 DEBUG [agent.transport.Request] (DirectAgent-370:null) Seq 1-1179875398: Executing:  { Cmd , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"s-20208-VM","wait":0}}] }
2014-12-01 00:01:03,294 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-370:null) Seq 1-1179875398: Executing request
2014-12-01 00:01:03,314 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking VirtualRouter to release Nic[5-2-2ec60f9f-5bb5-4216-8f3f-8063bb77c41f-192.168.140.109]
2014-12-01 00:01:03,318 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking SecurityGroupProvider to release Nic[5-2-2ec60f9f-5bb5-4216-8f3f-8063bb77c41f-192.168.140.109]
2014-12-01 00:01:03,321 DEBUG [network.guru.ControlNetworkGuru] (consoleproxy-1:null) Released nic: NicProfile[6-2-null-null-null
2014-12-01 00:01:03,330 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] (consoleproxy-1:null) Releasing ip address for reservationId=2ec60f9f-5bb5-4216-8f3f-8063bb77c41f, instance=7
2014-12-01 00:01:03,331 DEBUG [network.guru.PodBasedNetworkGuru] (consoleproxy-1:null) Released nic: NicProfile[7-2-null-null-null
2014-12-01 00:01:03,336 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully released network resources for the vm VM[ConsoleProxy|v-2-VM]
2014-12-01 00:01:03,337 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully cleanued up resources for the vm VM[ConsoleProxy|v-2-VM] in Starting state
2014-12-01 00:01:03,340 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Root volume is ready, need to place VM in volume's cluster
2014-12-01 00:01:03,340 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Vol[2|vm=2|ROOT] is READY, changing deployment plan to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
2014-12-01 00:01:03,341 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Deploy avoids pods: [1], clusters: null, hosts: [1]
2014-12-01 00:01:03,342 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_c4c53593@e1a69ee
2014-12-01 00:01:03,342 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 1073741824
2014-12-01 00:01:03,342 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: Yes
2014-12-01 00:01:03,342 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) This VM has last host_id specified, trying to choose the same host: 1
2014-12-01 00:01:03,345 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) The last host of this VM is in avoid set
2014-12-01 00:01:03,345 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Cannot choose the last host to deploy this VM 
2014-12-01 00:01:03,345 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching resources only under specified Cluster: 1
2014-12-01 00:01:03,357 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) The specified cluster is in avoid set, returning.
2014-12-01 00:01:03,357 INFO  [xen.resource.CitrixResourceBase] (DirectAgent-370:null) VM does not exist on XenServer2353b211-58cd-4725-abf6-83d1eec5ca05
2014-12-01 00:01:03,357 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-370:null) Seq 1-1179875398: Response Received: 
2014-12-01 00:01:03,357 DEBUG [agent.transport.Request] (DirectAgent-370:null) Seq 1-1179875398: Processing:  { Ans: , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"details":"VM does not exist","wait":0}}] }
2014-12-01 00:01:03,358 DEBUG [agent.manager.AgentAttache] (DirectAgent-370:null) Seq 1-1179875398: No more commands found
2014-12-01 00:01:03,358 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-1179875398: Received:  { Ans: , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2014-12-01 00:01:03,359 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Deploy avoids pods: [1], clusters: null, hosts: [1]
2014-12-01 00:01:03,360 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_c4c53593@e1a69ee
2014-12-01 00:01:03,360 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2014-12-01 00:01:03,360 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: No
2014-12-01 00:01:03,360 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) This VM has last host_id specified, trying to choose the same host: 1
2014-12-01 00:01:03,362 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) The last host of this VM is in avoid set
2014-12-01 00:01:03,362 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Cannot choose the last host to deploy this VM 
2014-12-01 00:01:03,362 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching resources only under specified Pod: 1
2014-12-01 00:01:03,362 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) The specified pod is in avoid set, returning.
2014-12-01 00:01:03,375 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: 1 new host id: null host id before state transition: 1
2014-12-01 00:01:03,377 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Asking VirtualRouter to release Nic[80818-20208-4e4f86a1-5493-406e-bf85-d2f7222181d7-192.168.140.110]
2014-12-01 00:01:03,380 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Asking SecurityGroupProvider to release Nic[80818-20208-4e4f86a1-5493-406e-bf85-d2f7222181d7-192.168.140.110]
2014-12-01 00:01:03,382 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Hosts's actual total CPU: 27136 and CPU after applying overprovisioning: 27136
2014-12-01 00:01:03,382 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Hosts's actual total RAM: 16073241408 and RAM after applying overprovisioning: 16073241600
2014-12-01 00:01:03,382 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) release cpu from host: 1, old used: 1000,reserved: 0, actual total: 27136, total with overprovisioning: 27136; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-12-01 00:01:03,382 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) release mem from host: 1, old used: 1342177280,reserved: 0, total: 16073241600; new used: 268435456,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-12-01 00:01:03,382 DEBUG [network.guru.ControlNetworkGuru] (secstorage-1:null) Released nic: NicProfile[80819-20208-null-null-null
2014-12-01 00:01:03,387 WARN  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Exception while trying to start console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-2-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2014-12-01 00:01:03,387 DEBUG [db.Transaction.Transaction] (secstorage-1:null) Rolling back the transaction: Time = 1 Name =  -SystemVmLoadScanner$1.run:70-Executors$RunnableAdapter.call:441-FutureTask$Sync.innerRunAndReset:317-FutureTask.runAndReset:150-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101:98-ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic:180-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:204-ThreadPoolExecutor$Worker.runTask:886-ThreadPoolExecutor$Worker.run:908-Thread.run:662; called by -Transaction.rollback:898-Transaction.removeUpTo:841-Transaction.close:665-TransactionContextBuilder.interceptComplete:56-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:131-NetworkManagerImpl.release:2385-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VirtualMachineManagerImpl.cleanup:1126-VirtualMachineManagerImpl.advanceStart:998-VirtualMachineManagerImpl.start:578-VirtualMachineManagerImpl.start:571-SecondaryStorageManagerImpl.startSecStorageVm:267
2014-12-01 00:01:03,389 DEBUG [db.Transaction.Transaction] (secstorage-1:null) Rolling back the transaction: Time = 1 Name =  -SystemVmLoadScanner$1.run:70-Executors$RunnableAdapter.call:441-FutureTask$Sync.innerRunAndReset:317-FutureTask.runAndReset:150-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101:98-ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic:180-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:204-ThreadPoolExecutor$Worker.runTask:886-ThreadPoolExecutor$Worker.run:908-Thread.run:662; called by -Transaction.rollback:898-Transaction.removeUpTo:841-Transaction.close:665-TransactionContextBuilder.interceptComplete:56-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:131-NetworkManagerImpl.release:2385-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VirtualMachineManagerImpl.cleanup:1126-VirtualMachineManagerImpl.advanceStart:998-VirtualMachineManagerImpl.start:578-VirtualMachineManagerImpl.start:571-SecondaryStorageManagerImpl.startSecStorageVm:267
2014-12-01 00:01:03,390 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Successfully released network resources for the vm VM[SecondaryStorageVm|s-20208-VM]
2014-12-01 00:01:03,390 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Successfully cleanued up resources for the vm VM[SecondaryStorageVm|s-20208-VM] in Starting state
2014-12-01 00:01:03,391 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: [1]
2014-12-01 00:01:03,391 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) DataCenter id = '1' provided is in avoid set, DeploymentPlanner cannot allocate the VM, returning.
2014-12-01 00:01:03,398 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 1
2014-12-01 00:01:03,402 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Hosts's actual total CPU: 27136 and CPU after applying overprovisioning: 27136
2014-12-01 00:01:03,402 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Hosts's actual total RAM: 16073241408 and RAM after applying overprovisioning: 16073241600
2014-12-01 00:01:03,402 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) release cpu from host: 1, old used: 500,reserved: 0, actual total: 27136, total with overprovisioning: 27136; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-12-01 00:01:03,402 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) release mem from host: 1, old used: 268435456,reserved: 0, total: 16073241600; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-12-01 00:01:03,406 WARN  [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Exception while trying to start secondary storage vm
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-20208-VM]Scope=interface com.cloud.dc.DataCenter; id=1
at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:267)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300)
at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123)
at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:204)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
2014-12-01 00:01:03,407 INFO  [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 20208, will recycle it and start a new one
2014-12-01 00:01:03,407 INFO  [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null) Primary secondary storage is not even started, wait until next turn
2014-12-01 00:01:03,461 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 
2014-12-01 00:01:03,463 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 
2014-12-01 00:01:03,480 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. 
2014-12-01 00:01:03,482 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. 
2014-12-01 00:01:06,147 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) StorageCollector is running...
2014-12-01 00:01:06,153 INFO  [storage.endpoint.DefaultEndPointSelector] (StatsCollector-1:null) No running ssvm is found, so command will be sent to LocalHostEndPoint
2014-12-01 00:01:06,160 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-446:null) Seq 1-1179875399: Executing request
2014-12-01 00:01:06,604 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-446:null) Seq 1-1179875399: Response Received: 
2014-12-01 00:01:06,604 DEBUG [agent.transport.Request] (StatsCollector-1:null) Seq 1-1179875399: Received:  { Ans: , MgmtId: 86530476470110, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2014-12-01 00:01:13,679 DEBUG [cloud.server.StatsCollector] (StatsCollector-1:null) VmStatsCollector is running...
2014-12-01 00:01:33,004 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2014-12-01 00:01:33,010 INFO  [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null) No running secondary storage vms found in datacenter id=1, starting one
2014-12-01 00:01:33,018 INFO  [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Found a stopped secondary storage vm, bring it up to running pool. secStorageVm vm id : 20208
2014-12-01 00:01:33,026 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) 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
2014-12-01 00:01:33,026 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Successfully transitioned to start state for VM[SecondaryStorageVm|s-20208-VM] reservation id = c6f92285-422c-4bf7-a1c2-b51287e35678
2014-12-01 00:01:33,032 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
2014-12-01 00:01:33,032 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-12-01 00:01:33,034 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-12-01 00:01:33,035 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_c4c53593@e1a69ee
2014-12-01 00:01:33,035 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 268435456
2014-12-01 00:01:33,036 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
2014-12-01 00:01:33,036 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Searching resources only under specified Pod: 1
2014-12-01 00:01:33,036 DEBUG [cloud.deploy.FirstFitPlanner] (secstorage-1:null) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2014-12-01 00:01:33,045 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
2014-12-01 00:01:33,045 DEBUG [allocator.impl.FirstFitAllocator] (secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  cluster:1
---------------------------------------------------------------------------------------------------
Confidentiality Notice: The information contained in this e-mail and any accompanying attachment(s) 
is intended only for the use of the intended recipient and may be confidential and/or privileged of 
Neusoft Corporation, its subsidiaries and/or its affiliates. If any reader of this communication is 
not the intended recipient, unauthorized use, forwarding, printing,  storing, disclosure or copying 
is strictly prohibited, and may be unlawful.If you have received this communication in error,please 
immediately notify the sender by return e-mail, and delete the original message and all copies from 
your system. Thank you. 
---------------------------------------------------------------------------------------------------
---------------------------------------------------------------------------------------------------
Confidentiality Notice: The information contained in this e-mail and any accompanying attachment(s) 
is intended only for the use of the intended recipient and may be confidential and/or privileged of 
Neusoft Corporation, its subsidiaries and/or its affiliates. If any reader of this communication is 
not the intended recipient, unauthorized use, forwarding, printing,  storing, disclosure or copying 
is strictly prohibited, and may be unlawful.If you have received this communication in error,please 
immediately notify the sender by return e-mail, and delete the original message and all copies from 
your system. Thank you. 
---------------------------------------------------------------------------------------------------