log里有这句
Network id=203 is already implemented 
Network id=202 is already implemented
Network id=201 is already implemented
Unable to get a management ip addressScope

说明ssvm试图找一个network来配置管理ip,但你配置的网络都已经使用了,不能给ssvm使用,所以应该是你的配置有问题,先查查配置,可能要重新装吧。

刘宇超  Richard Liu




发件人: wanghaicheng2...@gmail.com 
发送时间: 2013-11-18  10:21:55 
收件人: users-cn 
抄送: 
主题: ssvm不能启动 
 
XenServer6.0.2+CS3.05
二级存储虚拟机不能启动
2013-11-18 10:02:17,216 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking BareMetal to prepare for 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:17,216 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking SecurityGroupProvider to prepare for 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:17,216 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:17,216 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VpcVirtualRouter to prepare for 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:17,223 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Lock is acquired for network id 202 as a part of network 
implement
2013-11-18 10:02:17,223 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Network id=202 is already implemented
2013-11-18 10:02:17,223 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Lock is released for network id 202 as a part of network 
implement
2013-11-18 10:02:17,457 DEBUG [storage.snapshot.SnapshotSchedulerImpl] 
(SnapshotPollTask:null) Snapshot scheduler.poll is being called at 2013-11-18 
02:02:17 GMT
2013-11-18 10:02:17,459 DEBUG [storage.snapshot.SnapshotSchedulerImpl] 
(SnapshotPollTask:null) Got 0 snapshots to be executed at 2013-11-18 02:02:17 
GMT
2013-11-18 10:02:17,554 DEBUG 
[cloud.network.ExternalLoadBalancerUsageManagerImpl] 
(ExternalNetworkMonitor-1:null) External load balancer devices stats collector 
is running...
2013-11-18 10:02:17,642 DEBUG 
[network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) 
Found 0 running routers. 
2013-11-18 10:02:17,644 DEBUG 
[network.router.VirtualNetworkApplianceManagerImpl] 
(RouterStatusMonitor-1:null) Found 0 routers. 
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking JuniperSRX to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Netscaler to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking F5BigIp to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VirtualRouter to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Ovs to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking ExternalDhcpServer to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking BareMetal to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking SecurityGroupProvider to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,892 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VpcVirtualRouter to prepare for 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-169.254.0.173]
2013-11-18 10:02:17,895 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Lock is acquired for network id 201 as a part of network 
implement
2013-11-18 10:02:17,895 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Network id=201 is already implemented
2013-11-18 10:02:17,896 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Lock is released for network id 201 as a part of network 
implement
2013-11-18 10:02:18,117 DEBUG [network.guru.PodBasedNetworkGuru] 
(secstorage-1:null) Allocated a nic 
NicProfile[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16-null for 
VM[SecondaryStorageVm|s-862-VM]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking JuniperSRX to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Netscaler to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking F5BigIp to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VirtualRouter to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Ovs to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking ExternalDhcpServer to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking BareMetal to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking SecurityGroupProvider to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,201 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,202 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VpcVirtualRouter to prepare for 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.16]
2013-11-18 10:02:18,204 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Lock is acquired for network id 203 as a part of network 
implement
2013-11-18 10:02:18,205 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Network id=203 is already implemented
2013-11-18 10:02:18,206 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Lock is released for network id 203 as a part of network 
implement
2013-11-18 10:02:18,308 DEBUG [db.Transaction.Transaction] (secstorage-1:null) 
Rolling back the transaction: Time = 1 Name =  
-SystemVmLoadScanner$1.run:67-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRunAndReset:351-FutureTask.runAndReset:178-ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201:165-ScheduledThreadPoolExecutor$ScheduledFutureTask.run:267-ThreadPoolExecutor.runWorker:1110-ThreadPoolExecutor$Worker.run:603-Thread.run:679;
 called by 
-Transaction.rollback:859-DataCenterIpAddressDaoImpl.takeIpAddress:53-DatabaseCallback.intercept:30-DataCenterDaoImpl.allocatePrivateIpAddress:224-DatabaseCallback.intercept:30-PodBasedNetworkGuru.reserve:115-StorageNetworkGuru.reserve:119-NetworkManagerImpl.prepareNic:2134-NetworkManagerImpl.prepare:2105-VirtualMachineManagerImpl.advanceStart:747-VirtualMachineManagerImpl.start:467-VirtualMachineManagerImpl.start:460
2013-11-18 10:02:18,308 INFO  [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-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:117)
        at 
com.cloud.network.guru.StorageNetworkGuru.reserve(StorageNetworkGuru.java:119)
        at 
com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2134)
        at 
com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2105)
        at 
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:747)
        at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:467)
        at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:460)
        at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:253)
        at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:680)
        at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1299)
        at 
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:115)
        at 
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:46)
        at 
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:102)
        at 
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:30)
        at 
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:79)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:69)
        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at 
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-11-18 10:02:18,411 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Cleaning up resources for the vm 
VM[SecondaryStorageVm|s-862-VM] in Starting state
2013-11-18 10:02:18,414 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 
1-981601522: Sending  { Cmd , MgmtId: 233845175752474, via: 1, Ver: v1, Flags: 
100111, [{"StopCommand":{"isProxy":false,"vmName":"s-862-VM","wait":0}}] }
2013-11-18 10:02:18,414 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 
1-981601522: Executing:  { Cmd , MgmtId: 233845175752474, via: 1, Ver: v1, 
Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"s-862-VM","wait":0}}] 
}
2013-11-18 10:02:18,414 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-280:null) Seq 1-981601522: Executing request
2013-11-18 10:02:18,589 INFO  [xen.resource.CitrixResourceBase] 
(DirectAgent-280:null) VM does not exist on 
XenServercda3fb87-b76e-43af-bd8a-e7fbe17cdaff
2013-11-18 10:02:18,589 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-280:null) Seq 1-981601522: Response Received: 
2013-11-18 10:02:18,590 DEBUG [agent.transport.Request] (DirectAgent-280:null) 
Seq 1-981601522: Processing:  { Ans: , MgmtId: 233845175752474, via: 1, Ver: 
v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does 
not exist","wait":0}}] }
2013-11-18 10:02:18,590 DEBUG [agent.manager.AgentAttache] 
(DirectAgent-280:null) Seq 1-981601522: No more commands found
2013-11-18 10:02:18,590 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 
1-981601522: Received:  { Ans: , MgmtId: 233845175752474, via: 1, Ver: v1, 
Flags: 110, { StopAnswer } }
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking JuniperSRX to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Netscaler to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking F5BigIp to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VirtualRouter to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Ovs to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking ExternalDhcpServer to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking BareMetal to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking SecurityGroupProvider to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking CiscoNexus1000vVSM to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:18,795 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VpcVirtualRouter to release 
Nic[3340-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-10.30.18.21]
2013-11-18 10:02:19,087 DEBUG [network.guru.ControlNetworkGuru] 
(secstorage-1:null) Released nic: NicProfile[3341-862-null-null-null
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking JuniperSRX to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Netscaler to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking F5BigIp to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VirtualRouter to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Ovs to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking ExternalDhcpServer to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking BareMetal to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking SecurityGroupProvider to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking CiscoNexus1000vVSM to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,171 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VpcVirtualRouter to release 
Nic[3341-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,257 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] 
(secstorage-1:null) Releasing ip address for 
reservationId=7f0eb388-465a-4de5-a19f-06c310ddacfb, instance=3342
2013-11-18 10:02:19,338 DEBUG [network.guru.PodBasedNetworkGuru] 
(secstorage-1:null) Released nic: NicProfile[3342-862-null-null-null
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking JuniperSRX to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Netscaler to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking F5BigIp to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VirtualRouter to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Ovs to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking ExternalDhcpServer to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking BareMetal to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking SecurityGroupProvider to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking CiscoNexus1000vVSM to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,422 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VpcVirtualRouter to release 
Nic[3342-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,513 DEBUG [dc.dao.DataCenterIpAddressDaoImpl] 
(secstorage-1:null) Releasing ip address for 
reservationId=7f0eb388-465a-4de5-a19f-06c310ddacfb, instance=3343
2013-11-18 10:02:19,514 DEBUG [network.guru.PodBasedNetworkGuru] 
(secstorage-1:null) Released nic: NicProfile[3343-862-null-null-null
2013-11-18 10:02:19,597 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking JuniperSRX to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,597 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Netscaler to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,597 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking F5BigIp to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,597 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VirtualRouter to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,598 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking Ovs to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,598 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking ExternalDhcpServer to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,598 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking BareMetal to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,598 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking SecurityGroupProvider to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,598 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking CiscoNexus1000vVSM to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,598 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Asking VpcVirtualRouter to release 
Nic[3343-862-7f0eb388-465a-4de5-a19f-06c310ddacfb-null]
2013-11-18 10:02:19,598 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Successfully released network resources for the vm 
VM[SecondaryStorageVm|s-862-VM]
2013-11-18 10:02:19,598 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Successfully cleanued up resources for the vm 
VM[SecondaryStorageVm|s-862-VM] in Starting state
2013-11-18 10:02:19,601 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) DeploymentPlanner allocation algorithm: random
2013-11-18 10:02:19,602 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Trying to allocate a host and storage pools from dc:1, 
pod:1,cluster:null, requested cpu: 500, requested ram: 268435456
2013-11-18 10:02:19,602 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
2013-11-18 10:02:19,602 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Searching resources only under specified Pod: 1
2013-11-18 10:02:19,603 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
2013-11-18 10:02:19,604 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) CPUOverprovisioningFactor considered: 2.0
2013-11-18 10:02:19,613 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
2013-11-18 10:02:19,613 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Calling HostAllocators to find suitable hosts
2013-11-18 10:02:19,613 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1  pod:1  
cluster:1
2013-11-18 10:02:19,616 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 2 hosts to check 
for allocation: [Host[-38-Routing], Host[-1-Routing]]
2013-11-18 10:02:19,620 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Found 2 hosts for allocation after 
prioritization: [Host[-38-Routing], Host[-1-Routing]]
2013-11-18 10:02:19,620 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
2013-11-18 10:02:19,620 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Host name: xen-3, hostId: 38 is in 
avoid set, skipping this and trying other available hosts
2013-11-18 10:02:19,620 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Host name: xen2, hostId: 1 is in avoid 
set, skipping this and trying other available hosts
2013-11-18 10:02:19,620 DEBUG [allocator.impl.FirstFitAllocator] 
(secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 0 suitable 
hosts
2013-11-18 10:02:19,620 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) No suitable hosts found
2013-11-18 10:02:19,620 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) No suitable hosts found under this Cluster: 1
2013-11-18 10:02:19,620 DEBUG [cloud.deploy.FirstFitPlanner] 
(secstorage-1:null) Could not find suitable Deployment Destination for this VM 
under any clusters, returning. 
2013-11-18 10:02:19,789 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
2013-11-18 10:02:19,795 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) Hosts's actual total CPU: 19200 and CPU after applying 
overprovisioning: 38400
2013-11-18 10:02:19,795 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) release cpu from host: 1, old used: 13788,reserved: 0, 
actual total: 19200, total with overprovisioning: 38400; new used: 
13288,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-11-18 10:02:19,795 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) release mem from host: 1, old used: 5771362304,reserved: 0, 
total: 7871028480; new used: 5502926848,reserved:0; movedfromreserved: 
false,moveToReserveredfalse
2013-11-18 10:02:19,881 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-862-VM]Scope=interface 
com.cloud.dc.DataCenter; id=1
        at 
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:729)
        at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:467)
        at 
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:460)
        at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:253)
        at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:680)
        at 
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1299)
        at 
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:115)
        at 
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:46)
        at 
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:102)
        at 
com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:30)
        at 
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:79)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:69)
        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at 
java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at 
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-11-18 10:02:19,883 INFO  [storage.secondary.SecondaryStorageManagerImpl] 
(secstorage-1:null) Unable to start secondary storage vm for standby capacity, 
secStorageVm vm Id : 862, will recycle it and start a new one
2013-11-18 10:02:19,886 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) VM is already stopped: VM[SecondaryStorageVm|s-862-VM]
2013-11-18 10:02:19,973 DEBUG [cloud.capacity.CapacityManagerImpl] 
(secstorage-1:null) VM state transitted from :Stopped to Expunging with event: 
ExpungeOperationvm's original host id: null new host id: null host id before 
state transition: null
2013-11-18 10:02:19,977 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Destroying vm VM[SecondaryStorageVm|s-862-VM]
2013-11-18 10:02:19,977 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Cleaning up NICS
2013-11-18 10:02:19,977 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Cleaning network for vm: 862
2013-11-18 10:02:20,073 DEBUG [network.guru.DirectNetworkGuru] 
(secstorage-1:null) Deallocate network: networkId: 204, ip: 10.30.18.21
2013-11-18 10:02:20,241 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Removed nic id=3340
2013-11-18 10:02:20,491 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Removed nic id=3341
2013-11-18 10:02:20,667 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Removed nic id=3342
2013-11-18 10:02:20,843 DEBUG [cloud.network.NetworkManagerImpl] 
(secstorage-1:null) Removed nic id=3343
2013-11-18 10:02:20,843 DEBUG [cloud.storage.StorageManagerImpl] 
(secstorage-1:null) Cleaning storage for vm: 862
2013-11-18 10:02:20,934 DEBUG [cloud.storage.StorageManagerImpl] 
(secstorage-1:null) Expunging Vol[878|vm=862|ROOT]
2013-11-18 10:02:20,939 DEBUG [cloud.storage.StorageManagerImpl] 
(secstorage-1:null) Marking volume that was never created as destroyed: 
Vol[878|vm=862|ROOT]
2013-11-18 10:02:21,068 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
(secstorage-1:null) Expunged VM[SecondaryStorageVm|s-862-VM]
2013-11-18 10:02:21,171 INFO  
[cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null) 
Primary secondary storage is not even started, wait until next turn
2013-11-18 10:02:22,044 DEBUG [cloud.server.StatsCollector] 
(StatsCollector-2:null) VmStatsCollector is running...
2013-11-18 10:02:22,068 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-429:null) Seq 1-981601523: Executing request
2013-11-18 10:02:22,538 DEBUG [xen.resource.CitrixResourceBase] 
(DirectAgent-429:null) Vm cpu utilization 25.874999999999996
2013-11-18 10:02:22,538 DEBUG [xen.resource.CitrixResourceBase] 
(DirectAgent-429:null) Vm cpu utilization 31.169999999999998
2013-11-18 10:02:22,538 DEBUG [xen.resource.CitrixResourceBase] 
(DirectAgent-429:null) Vm cpu utilization 51.355
2013-11-18 10:02:22,538 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-429:null) Seq 1-981601523: Response Received: 
2013-11-18 10:02:22,538 DEBUG [agent.transport.Request] (StatsCollector-2:null) 
Seq 1-981601523: Received:  { Ans: , MgmtId: 233845175752474, via: 1, Ver: v1, 
Flags: 10, { GetVmStatsAnswer } }
2013-11-18 10:02:23,141 DEBUG [cloud.server.StatsCollector] 
(StatsCollector-2:null) StorageCollector is running...
2013-11-18 10:02:23,148 DEBUG [cloud.server.StatsCollector] 
(StatsCollector-2:null) There is no secondary storage VM for secondary storage 
host nfs://10.30.18.4/export/secondary4
2013-11-18 10:02:23,150 DEBUG [cloud.server.StatsCollector] 
(StatsCollector-2:null) There is no secondary storage VM for secondary storage 
host nfs://10.30.18.4/export/secondary2
2013-11-18 10:02:23,153 DEBUG [cloud.server.StatsCollector] 
(StatsCollector-2:null) There is no secondary storage VM for secondary storage 
host nfs://10.30.18.4/export/secondary1
2013-11-18 10:02:23,155 DEBUG [cloud.server.StatsCollector] 
(StatsCollector-2:null) There is no secondary storage VM for secondary storage 
host nfs://10.30.18.4/export/secondary3
2013-11-18 10:02:23,162 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-130:null) Seq 1-981601524: Executing request
2013-11-18 10:02:24,033 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-130:null) Seq 1-981601524: Response Received: 
2013-11-18 10:02:24,033 DEBUG [agent.transport.Request] (StatsCollector-2:null) 
Seq 1-981601524: Received:  { Ans: , MgmtId: 233845175752474, via: 1, Ver: v1, 
Flags: 10, { GetStorageStatsAnswer } }
2013-11-18 10:02:24,041 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-184:null) Seq 38-1135804443: Executing request
2013-11-18 10:02:24,991 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-184:null) Seq 38-1135804443: Response Received: 
2013-11-18 10:02:24,991 DEBUG [agent.transport.Request] (StatsCollector-2:null) 
Seq 38-1135804443: Received:  { Ans: , MgmtId: 233845175752474, via: 38, Ver: 
v1, Flags: 10, { GetStorageStatsAnswer } }
2013-11-18 10:02:26,723 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-350:null) Ping from 1
2013-11-18 10:02:32,950 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-283:null) Seq 1-981598214: Executing request
2013-11-18 10:02:33,434 DEBUG [agent.manager.DirectAgentAttache] 
(DirectAgent-283:null) Seq 1-981598214: Response Received: 
2013-11-18 10:02:33,434 DEBUG [agent.transport.Request] (DirectAgent-283:null) 
Seq 1-981598214: Processing:  { Ans: , MgmtId: 233845175752474, via: 1, Ver: 
v1, Flags: 10, 
[{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}]
 }
2013-11-18 10:02:33,434 DEBUG [agent.manager.AgentAttache] 
(DirectAgent-283:null) Seq 1-981598214: Unable to find listener.
wanghaicheng2...@gmail.com

回复