[ 
https://issues.apache.org/jira/browse/CLOUDSTACK-183?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

shweta agarwal updated CLOUDSTACK-183:
--------------------------------------

    Attachment: management-server.log
                SMlog
    
> hitting exception and system VM are not coming up
> -------------------------------------------------
>
>                 Key: CLOUDSTACK-183
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-183
>             Project: CloudStack
>          Issue Type: Bug
>          Components: Install and Setup
>    Affects Versions: pre-4.0.0
>         Environment: build:
> Git Revision: 0699d65ef155aeff60aab294987815251cc94900
> Git URL: https://git-wip-us.apache.org/repos/asf/incubator-cloudstack.git
>            Reporter: shweta agarwal
>            Priority: Blocker
>             Fix For: pre-4.0.0
>
>         Attachments: management-server.log, SMlog
>
>
> I have xen6.0.2
> I am trying to use build
> http://jenkins.cloudstack.org/job/build-4.0-rhel63/55/artifact/CloudStack-oss-4.0.0-55.tar.bz2
> hitting Exception MY MS log shows
> 2012-09-21 15:38:14,357 DEBUG [cloud.storage.StorageManagerImpl] 
> (consoleproxy-1:null) Checking if we need to prepare 1 volumes for 
> VM[ConsoleProxy|v-2-VM]
> 2012-09-21 15:38:14,370 DEBUG [cloud.storage.StorageManagerImpl] 
> (consoleproxy-1:null) Creating volume: Vol[2|vm=2|ROOT]
> 2012-09-21 15:38:14,370 DEBUG [cloud.storage.StorageManagerImpl] 
> (consoleproxy-1:null) Trying to create in Pool[200|NetworkFilesystem]
> 2012-09-21 15:38:14,393 DEBUG [cloud.template.TemplateManagerImpl] 
> (consoleproxy-1:null) Downloading template 1 to pool 200
> 2012-09-21 15:38:14,408 DEBUG [cloud.template.TemplateManagerImpl] 
> (consoleproxy-1:null) Downloading 1 via 1
> 2012-09-21 15:38:14,415 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493258: Sending  { Cmd , MgmtId: 59793358248320, via: 1, Ver: v1, 
> Flags: 100111, 
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/6ce86454-a33f-3551-a1df-bf9cf191dded","poolUuid":"6ce86454-a33f-3551-a1df-bf9cf191dded","poolId":200,"secondaryStorageUrl":"nfs://10.147.28.7/export/home/shweta/asfsecondary","primaryStorageUrl":"nfs://10.147.28.7/export/home/shweta/asfprimary","url":"nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
>  }
> 2012-09-21 15:38:14,416 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493258: Executing:  { Cmd , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 100111, 
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/6ce86454-a33f-3551-a1df-bf9cf191dded","poolUuid":"6ce86454-a33f-3551-a1df-bf9cf191dded","poolId":200,"secondaryStorageUrl":"nfs://10.147.28.7/export/home/shweta/asfsecondary","primaryStorageUrl":"nfs://10.147.28.7/export/home/shweta/asfprimary","url":"nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
>  }
> 2012-09-21 15:38:14,416 DEBUG [agent.manager.DirectAgentAttache] 
> (DirectAgent-5:null) Seq 1-1277493258: Executing request
> 2012-09-21 15:38:16,666 WARN  [xen.resource.CitrixResourceBase] 
> (DirectAgent-5:null) destoryVDIbyNameLabel failed due to there are 0 VDIs 
> with name cloud-4dd59ba5-e791-4289-9048-c925b28310ad
> 2012-09-21 15:38:16,666 WARN  [xen.resource.CitrixResourceBase] 
> (DirectAgent-5:null) can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
> 2012-09-21 15:38:16,667 WARN  [xen.resource.CitrixResourceBase] 
> (DirectAgent-5:null) Catch Exception 
> com.cloud.utils.exception.CloudRuntimeException on 
> host:186c239f-392e-4088-b5b2-03a4efc3c432 for template: 
> nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/ due to 
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
>       at 
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2672)
>       at 
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2694)
>       at 
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:481)
>       at 
> com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
>       at 
> com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
>       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:1110)
>       at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>       at java.lang.Thread.run(Thread.java:679)
> 2012-09-21 15:38:16,667 DEBUG [agent.manager.DirectAgentAttache] 
> (DirectAgent-5:null) Seq 1-1277493258: Response Received: 
> 2012-09-21 15:38:16,668 DEBUG [agent.transport.Request] (DirectAgent-5:null) 
> Seq 1-1277493258: Processing:  { Ans: , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 110, 
> [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch
>  Exception com.cloud.utils.exception.CloudRuntimeException on 
> host:186c239f-392e-4088-b5b2-03a4efc3c432 for template: 
> nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/ due to 
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef","wait":0}}] }
> 2012-09-21 15:38:16,668 DEBUG [agent.manager.AgentAttache] 
> (DirectAgent-5:null) Seq 1-1277493258: No more commands found
> 2012-09-21 15:38:16,668 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493258: Received:  { Ans: , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 110, { PrimaryStorageDownloadAnswer } }
> 2012-09-21 15:38:16,668 DEBUG [agent.manager.AgentManagerImpl] 
> (consoleproxy-1:null) Details from executing class 
> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception 
> com.cloud.utils.exception.CloudRuntimeException on 
> host:186c239f-392e-4088-b5b2-03a4efc3c432 for template: 
> nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/ due to 
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
> 2012-09-21 15:38:16,668 DEBUG [cloud.template.TemplateManagerImpl] 
> (consoleproxy-1:null) Template 1 download to pool 200 failed due to Catch 
> Exception com.cloud.utils.exception.CloudRuntimeException on 
> host:186c239f-392e-4088-b5b2-03a4efc3c432 for template: 
> nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/ due to 
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
> 2012-09-21 15:38:16,668 DEBUG [cloud.template.TemplateManagerImpl] 
> (consoleproxy-1:null) Downloading 1 via 1
> 2012-09-21 15:38:16,672 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493259: Sending  { Cmd , MgmtId: 59793358248320, via: 1, Ver: v1, 
> Flags: 100111, 
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/6ce86454-a33f-3551-a1df-bf9cf191dded","poolUuid":"6ce86454-a33f-3551-a1df-bf9cf191dded","poolId":200,"secondaryStorageUrl":"nfs://10.147.28.7/export/home/shweta/asfsecondary","primaryStorageUrl":"nfs://10.147.28.7/export/home/shweta/asfprimary","url":"nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
>  }
> 2012-09-21 15:38:16,672 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493259: Executing:  { Cmd , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 100111, 
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/6ce86454-a33f-3551-a1df-bf9cf191dded","poolUuid":"6ce86454-a33f-3551-a1df-bf9cf191dded","poolId":200,"secondaryStorageUrl":"nfs://10.147.28.7/export/home/shweta/asfsecondary","primaryStorageUrl":"nfs://10.147.28.7/export/home/shweta/asfprimary","url":"nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/","format":"VHD","accountId":1,"name":"routing-1","wait":10800}}]
>  }
> 2012-09-21 15:38:16,672 DEBUG [agent.manager.DirectAgentAttache] 
> (DirectAgent-2:null) Seq 1-1277493259: Executing request
> 2012-09-21 15:38:19,229 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Lock is acquired for network id 200 as a part of network 
> implement
> 2012-09-21 15:38:19,229 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Network id=200 is already implemented
> 2012-09-21 15:38:19,230 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Lock is released for network id 200 as a part of network 
> implement
> 2012-09-21 15:38:19,257 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking VirtualRouter to prepare for 
> Nic[1-1-null-10.147.51.80]
> 2012-09-21 15:38:19,258 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking Ovs to prepare for Nic[1-1-null-10.147.51.80]
> 2012-09-21 15:38:19,258 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking ExternalDhcpServer to prepare for 
> Nic[1-1-null-10.147.51.80]
> 2012-09-21 15:38:19,258 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking BareMetal to prepare for Nic[1-1-null-10.147.51.80]
> 2012-09-21 15:38:19,258 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking SecurityGroupProvider to prepare for 
> Nic[1-1-null-10.147.51.80]
> 2012-09-21 15:38:19,258 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking VpcVirtualRouter to prepare for 
> Nic[1-1-null-10.147.51.80]
> 2012-09-21 15:38:19,258 WARN  [network.element.VpcVirtualRouterElement] 
> (secstorage-1:null) Network Ntwk[200|Public|1] is not associated with any VPC
> 2012-09-21 15:38:19,258 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking NiciraNvp to prepare for Nic[1-1-null-10.147.51.80]
> 2012-09-21 15:38:19,261 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Lock is acquired for network id 202 as a part of network 
> implement
> 2012-09-21 15:38:19,261 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Network id=202 is already implemented
> 2012-09-21 15:38:19,262 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Lock is released for network id 202 as a part of network 
> implement
> 2012-09-21 15:38:19,297 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking VirtualRouter to prepare for 
> Nic[2-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-169.254.2.3]
> 2012-09-21 15:38:19,298 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking Ovs to prepare for 
> Nic[2-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-169.254.2.3]
> 2012-09-21 15:38:19,298 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking ExternalDhcpServer to prepare for 
> Nic[2-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-169.254.2.3]
> 2012-09-21 15:38:19,298 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking BareMetal to prepare for 
> Nic[2-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-169.254.2.3]
> 2012-09-21 15:38:19,298 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking SecurityGroupProvider to prepare for 
> Nic[2-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-169.254.2.3]
> 2012-09-21 15:38:19,298 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking VpcVirtualRouter to prepare for 
> Nic[2-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-169.254.2.3]
> 2012-09-21 15:38:19,298 WARN  [network.element.VpcVirtualRouterElement] 
> (secstorage-1:null) Network Ntwk[202|Control|3] is not associated with any VPC
> 2012-09-21 15:38:19,299 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking NiciraNvp to prepare for 
> Nic[2-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-169.254.2.3]
> 2012-09-21 15:38:19,302 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Lock is acquired for network id 201 as a part of network 
> implement
> 2012-09-21 15:38:19,302 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Network id=201 is already implemented
> 2012-09-21 15:38:19,303 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Lock is released for network id 201 as a part of network 
> implement
> 2012-09-21 15:38:19,335 DEBUG [network.guru.PodBasedNetworkGuru] 
> (secstorage-1:null) Allocated a nic 
> NicProfile[3-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.83-null for 
> VM[SecondaryStorageVm|s-1-VM]
> 2012-09-21 15:38:19,341 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking VirtualRouter to prepare for 
> Nic[3-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.83]
> 2012-09-21 15:38:19,342 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking Ovs to prepare for 
> Nic[3-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.83]
> 2012-09-21 15:38:19,342 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking ExternalDhcpServer to prepare for 
> Nic[3-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.83]
> 2012-09-21 15:38:19,342 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking BareMetal to prepare for 
> Nic[3-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.83]
> 2012-09-21 15:38:19,342 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking SecurityGroupProvider to prepare for 
> Nic[3-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.83]
> 2012-09-21 15:38:19,342 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking VpcVirtualRouter to prepare for 
> Nic[3-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.83]
> 2012-09-21 15:38:19,342 WARN  [network.element.VpcVirtualRouterElement] 
> (secstorage-1:null) Network Ntwk[201|Management|2] is not associated with any 
> VPC
> 2012-09-21 15:38:19,343 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking NiciraNvp to prepare for 
> Nic[3-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.83]
> 2012-09-21 15:38:19,346 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Lock is acquired for network id 203 as a part of network 
> implement
> 2012-09-21 15:38:19,346 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Network id=203 is already implemented
> 2012-09-21 15:38:19,347 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Lock is released for network id 203 as a part of network 
> implement
> 2012-09-21 15:38:19,375 DEBUG [network.guru.PodBasedNetworkGuru] 
> (secstorage-1:null) Allocated a nic 
> NicProfile[4-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.85-null for 
> VM[SecondaryStorageVm|s-1-VM]
> 2012-09-21 15:38:19,380 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking VirtualRouter to prepare for 
> Nic[4-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.85]
> 2012-09-21 15:38:19,380 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking Ovs to prepare for 
> Nic[4-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.85]
> 2012-09-21 15:38:19,380 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking ExternalDhcpServer to prepare for 
> Nic[4-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.85]
> 2012-09-21 15:38:19,380 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking BareMetal to prepare for 
> Nic[4-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.85]
> 2012-09-21 15:38:19,380 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking SecurityGroupProvider to prepare for 
> Nic[4-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.85]
> 2012-09-21 15:38:19,380 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking VpcVirtualRouter to prepare for 
> Nic[4-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.85]
> 2012-09-21 15:38:19,380 WARN  [network.element.VpcVirtualRouterElement] 
> (secstorage-1:null) Network Ntwk[203|Storage|4] is not associated with any VPC
> 2012-09-21 15:38:19,380 DEBUG [cloud.network.NetworkManagerImpl] 
> (secstorage-1:null) Asking NiciraNvp to prepare for 
> Nic[4-1-e08d0ec0-3ce0-4612-8d2b-8df333117546-10.147.41.85]
> 2012-09-21 15:38:19,382 DEBUG [cloud.storage.StorageManagerImpl] 
> (secstorage-1:null) Checking if we need to prepare 1 volumes for 
> VM[SecondaryStorageVm|s-1-VM]
> 2012-09-21 15:38:19,387 DEBUG [cloud.storage.StorageManagerImpl] 
> (secstorage-1:null) Creating volume: Vol[1|vm=1|ROOT]
> 2012-09-21 15:38:19,387 DEBUG [cloud.storage.StorageManagerImpl] 
> (secstorage-1:null) Trying to create in Pool[200|NetworkFilesystem]
> 2012-09-21 15:38:20,902 WARN  [xen.resource.CitrixResourceBase] 
> (DirectAgent-2:null) destoryVDIbyNameLabel failed due to there are 0 VDIs 
> with name cloud-9ebc9ab1-a421-4d24-8984-ea443c109491
> 2012-09-21 15:38:20,902 WARN  [xen.resource.CitrixResourceBase] 
> (DirectAgent-2:null) can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
> 2012-09-21 15:38:20,902 WARN  [xen.resource.CitrixResourceBase] 
> (DirectAgent-2:null) Catch Exception 
> com.cloud.utils.exception.CloudRuntimeException on 
> host:186c239f-392e-4088-b5b2-03a4efc3c432 for template: 
> nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/ due to 
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
>       at 
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.copy_vhd_from_secondarystorage(CitrixResourceBase.java:2672)
>       at 
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:2694)
>       at 
> com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:481)
>       at 
> com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
>       at 
> com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
>       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:1110)
>       at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>       at java.lang.Thread.run(Thread.java:679)
> 2012-09-21 15:38:20,904 DEBUG [agent.manager.DirectAgentAttache] 
> (DirectAgent-2:null) Seq 1-1277493259: Response Received: 
> 2012-09-21 15:38:20,904 DEBUG [agent.transport.Request] (DirectAgent-2:null) 
> Seq 1-1277493259: Processing:  { Ans: , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 110, 
> [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Catch
>  Exception com.cloud.utils.exception.CloudRuntimeException on 
> host:186c239f-392e-4088-b5b2-03a4efc3c432 for template: 
> nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/ due to 
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef","wait":0}}] }
> 2012-09-21 15:38:20,905 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493259: Received:  { Ans: , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 110, { PrimaryStorageDownloadAnswer } }
> 2012-09-21 15:38:20,905 DEBUG [agent.manager.AgentManagerImpl] 
> (consoleproxy-1:null) Details from executing class 
> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Catch Exception 
> com.cloud.utils.exception.CloudRuntimeException on 
> host:186c239f-392e-4088-b5b2-03a4efc3c432 for template: 
> nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/ due to 
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
> 2012-09-21 15:38:20,905 DEBUG [cloud.template.TemplateManagerImpl] 
> (consoleproxy-1:null) Template 1 download to pool 200 failed due to Catch 
> Exception com.cloud.utils.exception.CloudRuntimeException on 
> host:186c239f-392e-4088-b5b2-03a4efc3c432 for template: 
> nfs://10.147.28.7/export/home/shweta/asfsecondary/template/tmpl/1/1/ due to 
> com.cloud.utils.exception.CloudRuntimeException: can not create vdi in sr 
> 7978e087-b632-8349-78e7-d3c6e7effeef
> 2012-09-21 15:38:20,905 DEBUG [agent.manager.AgentAttache] 
> (DirectAgent-2:null) Seq 1-1277493259: No more commands found
> 2012-09-21 15:38:20,906 DEBUG [cloud.template.TemplateManagerImpl] 
> (consoleproxy-1:null) Template 1 is not found on and can not be downloaded to 
> pool 200
> 2012-09-21 15:38:20,906 DEBUG [cloud.storage.StorageManagerImpl] 
> (consoleproxy-1:null) Cannot use this pool Pool[200|NetworkFilesystem] 
> because we can't propagate template Tmpl[1-VHD-routing-1
> 2012-09-21 15:38:20,912 INFO  [cloud.vm.VirtualMachineManagerImpl] 
> (consoleproxy-1:null) Unable to contact resource.
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:200] 
> is unreachable: Unable to create Vol[2|vm=2|ROOT]
>       at 
> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3361)
>       at 
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>       at 
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>       at 
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>       at 
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:624)
>       at 
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1154)
>       at 
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1965)
>       at 
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:170)
>       at 
> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>       at 
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>       at 
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>       at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>       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)
> 2012-09-21 15:38:20,918 DEBUG [cloud.vm.VirtualMachineManagerImpl] 
> (consoleproxy-1:null) Cleaning up resources for the vm 
> VM[ConsoleProxy|v-2-VM] in Starting state
> 2012-09-21 15:38:20,922 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493260: Sending  { Cmd , MgmtId: 59793358248320, via: 1, Ver: v1, 
> Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-2-VM","wait":0}}] 
> }
> 2012-09-21 15:38:20,922 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493260: Executing:  { Cmd , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 100111, 
> [{"StopCommand":{"isProxy":false,"vmName":"v-2-VM","wait":0}}] }
> 2012-09-21 15:38:20,922 DEBUG [agent.manager.DirectAgentAttache] 
> (DirectAgent-6:null) Seq 1-1277493260: Executing request
> 2012-09-21 15:38:21,019 INFO  [xen.resource.CitrixResourceBase] 
> (DirectAgent-6:null) VM does not exist on 
> XenServer186c239f-392e-4088-b5b2-03a4efc3c432
> 2012-09-21 15:38:21,019 DEBUG [agent.manager.DirectAgentAttache] 
> (DirectAgent-6:null) Seq 1-1277493260: Response Received: 
> 2012-09-21 15:38:21,020 DEBUG [agent.transport.Request] (DirectAgent-6:null) 
> Seq 1-1277493260: Processing:  { Ans: , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"details":"VM does 
> not exist","wait":0}}] }
> 2012-09-21 15:38:21,020 DEBUG [agent.manager.AgentAttache] 
> (DirectAgent-6:null) Seq 1-1277493260: No more commands found
> 2012-09-21 15:38:21,021 DEBUG [agent.transport.Request] (consoleproxy-1:null) 
> Seq 1-1277493260: Received:  { Ans: , MgmtId: 59793358248320, via: 1, Ver: 
> v1, Flags: 110, { StopAnswer } }
> 2012-09-21 15:38:21,050 DEBUG [network.guru.ControlNetworkGuru] 
> (consoleproxy-1:null) Released nic: NicProfile[6-2-null-null-null
> 2012-09-21 15:38:21,055 DEBUG [cloud.network.NetworkManagerImpl] 
> (consoleproxy-1:null) Asking VirtualRouter to release 
> Attaching MS log
> SMlog
> When executing
>  /opt/xensource/bin/copy_vhd_from_secondarystorage.sh 
> 10.147.28.7:/export/home/shweta/asfsecondary/template/tmpl/1/1/ 
> 7978e087-b632-8349-78e7-d3c6e7effeef  
> cloud-d4969150-9a80-4b5b-b87c-fed6a15b39bc
> Getting exception
> /opt/xensource/bin/vhd-util query -v -n 
> /var/run/cloud_mount/f0072628-7275-46f9-a715-6775b8af905a//d90f2df0-f44b-4b1d-ba8a-d33788720158.vhd
> /opt/xensource/bin/copy_vhd_from_secondarystorage.sh: line 133: 
> /opt/xensource/bin/vhd-util: No such file or directory

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Reply via email to