Hello all,
Trying to install subj. several times I have decided to ask your
help. May be someone already faced the same problem? I did the configuration
according to “Installation guide” and always end up with the same problem: on
system VM creation I got repeated errors like this:
2013-09-18 16:49:21,605 DEBUG [cloud.storage.StorageManagerImpl]
(consoleproxy-1:null) Creating volume: Vol[2|vm=2|ROOT]
2013-09-18 16:49:21,605 DEBUG [cloud.storage.StorageManagerImpl]
(consoleproxy-1:null) Trying to create in Pool[200|NetworkFilesystem]
2013-09-18 16:49:23,381 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-4:null) kill_copy_process failed
2013-09-18 16:49:23,381 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-4:null) can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
2013-09-18 16:49:23,382 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-4:null) Catch Exception
com.cloud.utils.exception.CloudRuntimeException on
host:e6a339ee-521c-4c67-ac55-cbd256607150 for template:
nfs://192.168.107.142/export/secondary/template/tmpl/1/1/ due to
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2707)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2729)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:501)
at
com.cloud.hypervisor.xen.resource.XcpServerResource.executeRequest(XcpServerResource.java:51)
at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-09-18 16:49:23,384 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-4:null) Seq 1-1333067786: Response Received:
2013-09-18 16:49:23,385 DEBUG [agent.transport.Request] (DirectAgent-4:null)
Seq 1-1333067786: Processing: { Ans: , MgmtId: 8796752993784, via: 1, Ver: v1,
Flags: 110,
[{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch
Exception com.cloud.utils.exception.CloudRuntimeException on
host:e6a339ee-521c-4c67-ac55-cbd256607150 for template:
nfs://192.168.107.142/export/secondary/template/tmpl/1/1/ due to
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6","wait":0}}] }
2013-09-18 16:49:23,385 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1333067786: Received: { Ans: , MgmtId: 8796752993784, via: 1, Ver: v1,
Flags: 110, { PrimaryStorageDownloadAnswer } }
2013-09-18 16:49:23,385 DEBUG [agent.manager.AgentManagerImpl]
(secstorage-1:null) Details from executing class
com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception
com.cloud.utils.exception.CloudRuntimeException on
host:e6a339ee-521c-4c67-ac55-cbd256607150 for template:
nfs://192.168.107.142/export/secondary/template/tmpl/1/1/ due to
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
2013-09-18 16:49:23,386 DEBUG [cloud.template.TemplateManagerImpl]
(secstorage-1:null) Template 1 download to pool 200 failed due to Catch
Exception com.cloud.utils.exception.CloudRuntimeException on
host:e6a339ee-521c-4c67-ac55-cbd256607150 for template:
nfs://192.168.107.142/export/secondary/template/tmpl/1/1/ due to
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
2013-09-18 16:49:23,386 DEBUG [cloud.template.TemplateManagerImpl]
(secstorage-1:null) Downloading 1 via 1
2013-09-18 16:49:23,394 DEBUG [agent.manager.AgentAttache] (DirectAgent-4:null)
Seq 1-1333067786: No more commands found
2013-09-18 16:49:23,411 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1333067787: Sending { Cmd , MgmtId: 8796752993784, via: 1, Ver: v1, Flags:
100111,
[{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/964f362d-c1cf-3e3b-a5fc-c013777b0e36","poolUuid":"964f362d-c1cf-3e3b-a5fc-c013777b0e36","poolId":200,"primaryPool":{"id":200,"uuid":"964f362d-c1cf-3e3b-a5fc-c013777b0e36","host":"192.168.107.142","path":"/export/primary","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://192.168.107.142/export/secondary","primaryStorageUrl":"nfs://192.168.107.142/export/primary","url":"nfs://192.168.107.142/export/secondary/template/tmpl/1/1/","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
}
2013-09-18 16:49:23,412 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1333067787: Executing: { Cmd , MgmtId: 8796752993784, via: 1, Ver: v1,
Flags: 100111,
[{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/964f362d-c1cf-3e3b-a5fc-c013777b0e36","poolUuid":"964f362d-c1cf-3e3b-a5fc-c013777b0e36","poolId":200,"primaryPool":{"id":200,"uuid":"964f362d-c1cf-3e3b-a5fc-c013777b0e36","host":"192.168.107.142","path":"/export/primary","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://192.168.107.142/export/secondary","primaryStorageUrl":"nfs://192.168.107.142/export/primary","url":"nfs://192.168.107.142/export/secondary/template/tmpl/1/1/","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
}
2013-09-18 16:49:23,412 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-5:null) Seq 1-1333067787: Executing request
2013-09-18 16:49:25,604 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-5:null) kill_copy_process failed
2013-09-18 16:49:25,605 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-5:null) can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
2013-09-18 16:49:25,605 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-5:null) Catch Exception
com.cloud.utils.exception.CloudRuntimeException on
host:e6a339ee-521c-4c67-ac55-cbd256607150 for template:
nfs://192.168.107.142/export/secondary/template/tmpl/1/1/ due to
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2707)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2729)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:501)
at
com.cloud.hypervisor.xen.resource.XcpServerResource.executeRequest(XcpServerResource.java:51)
at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at
java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-09-18 16:49:25,606 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-5:null) Seq 1-1333067787: Response Received:
2013-09-18 16:49:25,607 DEBUG [agent.transport.Request] (DirectAgent-5:null)
Seq 1-1333067787: Processing: { Ans: , MgmtId: 8796752993784, via: 1, Ver: v1,
Flags: 110,
[{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch
Exception com.cloud.utils.exception.CloudRuntimeException on
host:e6a339ee-521c-4c67-ac55-cbd256607150 for template:
nfs://192.168.107.142/export/secondary/template/tmpl/1/1/ due to
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6","wait":0}}] }
2013-09-18 16:49:25,607 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1333067787: Received: { Ans: , MgmtId: 8796752993784, via: 1, Ver: v1,
Flags: 110, { PrimaryStorageDownloadAnswer } }
2013-09-18 16:49:25,607 DEBUG [agent.manager.AgentManagerImpl]
(secstorage-1:null) Details from executing class
com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception
com.cloud.utils.exception.CloudRuntimeException on
host:e6a339ee-521c-4c67-ac55-cbd256607150 for template:
nfs://192.168.107.142/export/secondary/template/tmpl/1/1/ due to
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
2013-09-18 16:49:25,607 DEBUG [cloud.template.TemplateManagerImpl]
(secstorage-1:null) Template 1 download to pool 200 failed due to Catch
Exception com.cloud.utils.exception.CloudRuntimeException on
host:e6a339ee-521c-4c67-ac55-cbd256607150 for template:
nfs://192.168.107.142/export/secondary/template/tmpl/1/1/ due to
com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr
c6e55039-1fb0-5e5d-37d5-118a9ac3abb6
2013-09-18 16:49:25,608 DEBUG [cloud.template.TemplateManagerImpl]
(secstorage-1:null) Template 1 is not found on and can not be downloaded to
pool 200
2013-09-18 16:49:25,608 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Cannot use this pool Pool[200|NetworkFilesystem] because we
can't propagate template Tmpl[1-VHD-routing-1
2013-09-18 16:49:25,612 DEBUG [agent.manager.AgentAttache] (DirectAgent-5:null)
Seq 1-1333067787: No more commands found
2013-09-18 16:49:25,618 INFO [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:200] is
unreachable: Unable to create Vol[1|vm=1|ROOT]
at
com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3488)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:748)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:269)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1307)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
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: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:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-09-18 16:49:25,625 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Cleaning up resources for the vm
VM[SecondaryStorageVm|s-1-VM] in Starting state
2013-09-18 16:49:25,627 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1333067788: Sending { Cmd , MgmtId: 8796752993784, via: 1, Ver: v1, Flags:
100111, [{"StopCommand":{"isProxy":false,"vmName":"s-1-VM","wait":0}}] }
2013-09-18 16:49:25,628 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1333067788: Executing: { Cmd , MgmtId: 8796752993784, via: 1, Ver: v1,
Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"s-1-VM","wait":0}}] }
2013-09-18 16:49:25,628 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-6:null) Seq 1-1333067788: Executing request
2013-09-18 16:49:25,640 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null)
===START=== 192.168.107.75 -- GET
command=listSystemVms&response=json&sessionkey=zvxEneqJ%2FkCeNEEDUkDxJiXnhBc%3D&_=1379512165664
2013-09-18 16:49:25,689 INFO [xen.resource.CitrixResourceBase]
(DirectAgent-6:null) VM does not exist on
XenServere6a339ee-521c-4c67-ac55-cbd256607150
2013-09-18 16:49:25,690 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-6:null) Seq 1-1333067788: Response Received:
2013-09-18 16:49:25,690 DEBUG [agent.transport.Request] (DirectAgent-6:null)
Seq 1-1333067788: Processing: { Ans: , MgmtId: 8796752993784, via: 1, Ver: v1,
Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does not
exist","wait":0}}] }
2013-09-18 16:49:25,690 DEBUG [agent.transport.Request] (secstorage-1:null) Seq
1-1333067788: Received: { Ans: , MgmtId: 8796752993784, via: 1, Ver: v1,
Flags: 110, { StopAnswer } }
2013-09-18 16:49:25,692 DEBUG [agent.manager.AgentAttache] (DirectAgent-6:null)
Seq 1-1333067788: No more commands found
2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
2013-09-18 16:49:25,716 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[1-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-192.168.107.117]
2013-09-18 16:49:25,716 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network defaultGuestNetwork
2013-09-18 16:49:25,721 DEBUG [network.guru.ControlNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[2-1-null-null-null
2013-09-18 16:49:25,724 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,725 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,725 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,725 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,725 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[2-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,725 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2013-09-18 16:49:25,733 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(secstorage-1:null) Releasing ip address for
reservationId=7ab6fd6f-027f-4e3d-b70d-78474d479424, instance=3
2013-09-18 16:49:25,735 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[3-1-null-null-null
2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,740 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[3-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,740 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2013-09-18 16:49:25,749 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(secstorage-1:null) Releasing ip address for
reservationId=7ab6fd6f-027f-4e3d-b70d-78474d479424, instance=4
2013-09-18 16:49:25,751 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[4-1-null-null-null
2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,753 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[4-1-7ab6fd6f-027f-4e3d-b70d-78474d479424-null]
2013-09-18 16:49:25,753 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2013-09-18 16:49:25,753 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully released network resources for the vm
VM[SecondaryStorageVm|s-1-VM]
2013-09-18 16:49:25,754 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully cleanued up resources for the vm
VM[SecondaryStorageVm|s-1-VM] in Starting state
2013-09-18 16:49:25,756 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) DeploymentPlanner allocation algorithm: random
2013-09-18 16:49:25,756 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Trying to allocate a host and storage pools from dc:1,
pod:null,cluster:null, requested cpu: 500, requested ram: 268435456
2013-09-18 16:49:25,756 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
2013-09-18 16:49:25,756 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Searching all possible resources under this Zone: 1
2013-09-18 16:49:25,759 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 Zone: 1
2013-09-18 16:49:25,762 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
2013-09-18 16:49:25,776 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
2013-09-18 16:49:25,776 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
cluster:1
2013-09-18 16:49:25,779 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check
for allocation: [Host[-1-Routing]]
2013-09-18 16:49:25,788 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
prioritization: [Host[-1-Routing]]
2013-09-18 16:49:25,789 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
2013-09-18 16:49:25,789 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Host name: xen4export, hostId: 1 is in
avoid set, skipping this and trying other available hosts
2013-09-18 16:49:25,789 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 0 suitable
hosts
2013-09-18 16:49:25,789 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) No suitable hosts found
2013-09-18 16:49:25,789 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) No suitable hosts found under this Cluster: 1
2013-09-18 16:49:25,789 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Could not find suitable Deployment Destination for this VM
under any clusters, returning.
2013-09-18 16:49:25,807 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-09-18 16:49:25,820 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Hosts's actual total CPU: 11732 and CPU after applying
overprovisioning: 11732
2013-09-18 16:49:25,820 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release cpu from host: 1, old used: 1000,reserved: 0,
actual total: 11732, total with overprovisioning: 11732; new used:
500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-09-18 16:49:25,820 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release mem from host: 1, old used: 1342177280,reserved: 0,
total: 12056611392; new used: 1073741824,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2013-09-18 16:49:25,825 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-1-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:728)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:269)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1307)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
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: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:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
Please, help to find the root of the problem
Thank you,
Vadim Kimlaychuk
