You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "venkata swamybabu budumuru (JIRA)" <ji...@apache.org> on 2013/07/26 09:41:48 UTC
[jira] [Commented] (CLOUDSTACK-3845) [SystemVMTemplate] Unable to
deploy router VM due to "Template 1 has not been completely downloaded to
zone 2"
[ https://issues.apache.org/jira/browse/CLOUDSTACK-3845?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13720497#comment-13720497 ]
venkata swamybabu budumuru commented on CLOUDSTACK-3845:
--------------------------------------------------------
Here is the secondary and primary storages used for zone2.
mysql> select * from image_store where data_center_id=2 and removed is null\G
*************************** 1. row ***************************
id: 3
name: secondary2
image_provider_name: NFS
protocol: nfs
url: nfs://10.147.28.7/export/home/swamy/secondary.campo.xen.1
data_center_id: 2
scope: ZONE
role: Image
uuid: 33488884-0da7-44b1-bc4a-adad3b3a09b1
parent: b814c66e-9d67-3f4a-bf26-51e9c8a20324
created: 2013-07-26 04:44:22
removed: NULL
total_size: NULL
used_bytes: NULL
1 row in set (0.00 sec)
mysql> select * from storage_pool where data_center_id=2\G
*************************** 1. row ***************************
id: 4
name: primary2
uuid: 34044426-5416-39e0-b313-0bc2c0c216da
pool_type: NetworkFilesystem
port: 2049
data_center_id: 2
pod_id: 2
cluster_id: 2
used_bytes: 1999840018432
capacity_bytes: 5902284816384
host_address: 10.147.28.7
user_info: NULL
path: /export/home/swamy/primary.campo.kvm.1.cluster
created: 2013-07-26 04:41:04
removed: NULL
update_time: NULL
status: Up
storage_provider_name: DefaultPrimary
scope: CLUSTER
hypervisor: NULL
managed: 0
capacity_iops: NULL
1 row in set (0.00 sec)
> [SystemVMTemplate] Unable to deploy router VM due to "Template 1 has not been completely downloaded to zone 2"
> --------------------------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-3845
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3845
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Storage Controller
> Affects Versions: 4.2.0
> Environment: commit # ca474d0e09f772cb22abf2802a308a2da5351592
> Reporter: venkata swamybabu budumuru
> Priority: Critical
> Fix For: 4.2.0
>
>
> Steps to reproduce :
> ===============
> NOTE : Not really sure whether it is always reproducible
> (1) CloudStack latest build with zone1 (advanced) with KVM already existing in the setup.
> (2) Created Zone2 (advanced) with XenServer
> (3) By mistake, added a wrong secondary storage to Zone2 (when I say wrong, I mean it doesn't have template/tmpl/1/1 folder at all in this secondary storage) hence, removed the wrongly added one and added a right secondary store.
> Note : I am including the above step for your reference though it is not really required to mention.
> (4) Enabled zone2
> Observations:
> (i) It tried to bring up s-9-VM and v-8-VM. Mentioned below are the log snippets
> (a.) It initiated a copy command from secondary to primary for template 1
> 36025 2013-07-26 10:14:42,891 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Checking pool 4 for storage, totalSize: 5902284816384, usedBytes: 3898521288704, usedPct: 0.6605105327825244, disable threshold: 0.85
> 36026 2013-07-26 10:14:42,906 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 5-498335767: Sending { Cmd , MgmtId: 7280707764394, via: 5, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to .TemplateObjectTO":{"path":"template/tmpl/1/1/","origUrl":"http://10.147.28.7/templates/acton/acton-systemvm-02062012.vhd.bz2","uuid":"4cdfb5c8-f4ef-11e2-a91c-069f2c0000aa","id":1,"format":"VHD","accountId":1,"checksum":"f613f38c96bf039f2e5cbf92fa8ad4f8","hvm":f alse,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/swamy/secondary.campo.xen.1","_role":"Image"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.clou dstack.storage.to.TemplateObjectTO":{"origUrl":"http://10.147.28.7/templates/acton/acton-systemvm-02062012.vhd.bz2","uuid":"4cdfb5c8-f4ef-11e2-a91c-069f2c0000aa","id":1,"format":"VHD","accountId":1,"checksum":"f613f38c96bf039f2e5cbf92fa8ad4f8","hvm":false,"displ ayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"34044426-5416-39e0-b313-0bc2c0c216da","id":4,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/swamy/primary.campo.kvm .1.cluster","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"executeInSequence":false,"wait":10800}}] }
> 36336 2013-07-26 10:16:54,438 DEBUG [agent.transport.Request] (DirectAgent-15:null) Seq 5-498335767: Processing: { Ans: , MgmtId: 7280707764394, via: 5, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.sto rage.to.TemplateObjectTO":{"path":"60158049-e78a-467f-8ea9-d2e64601b949","uuid":"60158049-e78a-467f-8ea9-d2e64601b949","id":0,"format":"VHD","accountId":0,"hvm":false}},"result":true,"wait":0}}] }
> 36337 2013-07-26 10:16:54,438 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 5-498335767: Received: { Ans: , MgmtId: 7280707764394, via: 5, Ver: v1, Flags: 10, { CopyCmdAnswer } }
> (b.) one of the snippet from mgmt server log that says that it tried to create volumes for both s-9-VM and v-8-VM
> 36338 2013-07-26 10:16:54,489 DEBUG [storage.motion.AncientDataMotionStrategy] (secstorage-1:null) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME
> 36339 2013-07-26 10:16:54,541 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 5-498335773: Sending { Cmd , MgmtId: 7280707764394, via: 5, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to .TemplateObjectTO":{"path":"60158049-e78a-467f-8ea9-d2e64601b949","origUrl":"http://10.147.28.7/templates/acton/acton-systemvm-02062012.vhd.bz2","uuid":"4cdfb5c8-f4ef-11e2-a91c-069f2c0000aa","id":1,"format":"VHD","accountId":1,"checksum":"f613f38c96bf039f2e5cbf9 2fa8ad4f8","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"34044426-5416-39e0-b313-0bc2c0c216da","id":4,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export /home/swamy/primary.campo.kvm.1.cluster","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9e8b2e87-9ec3-4bf9-a3f9-b52f9d5887f9","volumeType":"ROOT","dataStore":{"org.apache.cloud stack.storage.to.PrimaryDataStoreTO":{"uuid":"34044426-5416-39e0-b313-0bc2c0c216da","id":4,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/swamy/primary.campo.kvm.1.cluster","port":2049}},"name":"ROOT-9","size":0,"volumeId":11,"vmName":" s-9-VM","accountId":1,"format":"VHD","id":11,"hypervisorType":"None"}},"executeInSequence":false,"wait":0}}] }
> 36340 2013-07-26 10:16:54,544 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 5-498335773: Executing: { Cmd , MgmtId: 7280707764394, via: 5, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage .to.TemplateObjectTO":{"path":"60158049-e78a-467f-8ea9-d2e64601b949","origUrl":"http://10.147.28.7/templates/acton/acton-systemvm-02062012.vhd.bz2","uuid":"4cdfb5c8-f4ef-11e2-a91c-069f2c0000aa","id":1,"format":"VHD","accountId":1,"checksum":"f613f38c96bf039f2e5c bf92fa8ad4f8","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"34044426-5416-39e0-b313-0bc2c0c216da","id":4,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/exp ort/home/swamy/primary.campo.kvm.1.cluster","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9e8b2e87-9ec3-4bf9-a3f9-b52f9d5887f9","volumeType":"ROOT","dataStore":{"org.apache.cl oudstack.storage.to.PrimaryDataStoreTO":{"uuid":"34044426-5416-39e0-b313-0bc2c0c216da","id":4,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/swamy/primary.campo.kvm.1.cluster","port":2049}},"name":"ROOT-9","size":0,"volumeId":11,"vmName ":"s-9-VM","accountId":1,"format":"VHD","id":11,"hypervisorType":"None"}},"executeInSequence":false,"wait":0}}] }
> 36355 2013-07-26 10:16:55,403 DEBUG [xen.resource.XenServerStorageProcessor] (DirectAgent-20:null) Succesfully created VDI: Uuid = b8dfbcbb-46c9-4d12-a738-7e7e539ff418
> 36356 2013-07-26 10:16:55,412 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-20:null) Seq 5-498335773: Response Received:
> 36357 2013-07-26 10:16:55,414 DEBUG [agent.transport.Request] (DirectAgent-20:null) Seq 5-498335773: Processing: { Ans: , MgmtId: 7280707764394, via: 5, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.sto rage.to.VolumeObjectTO":{"name":"ROOT-9","size":2097152000,"path":"b8dfbcbb-46c9-4d12-a738-7e7e539ff418","accountId":0,"id":0}},"result":true,"wait":0}}] }
> ****** (c.) Once the SSVM is up, it initiated template sync. mentioned below is the snippet for the same
> 36969 2013-07-26 10:19:17,670 DEBUG [agent.transport.Request] (AgentConnectTaskPool-5:null) Seq 6-1226899461: Received: { Ans: , MgmtId: 7280707764394, via: 6, Ver: v1, Flags: 110, { ListTemplateAnswer } }
> 36970 2013-07-26 10:19:17,698 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Template Sync did not find routing-1 on image store 3, may request download based on available hypervisor types
> 36971 2013-07-26 10:19:17,698 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Removing leftover template routing-1 entry from template store table
> 36972 2013-07-26 10:19:17,707 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Template Sync did not find routing-3 on image store 3, may request download based on available hypervisor types
> 36973 2013-07-26 10:19:17,707 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Removing leftover template routing-3 entry from template store table
> 36974 2013-07-26 10:19:17,727 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Template Sync did not find routing-8 on image store 3, may request download based on available hypervisor types
> 36975 2013-07-26 10:19:17,727 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Removing leftover template routing-8 entry from template store table
> 36976 2013-07-26 10:19:17,734 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Template Sync did not find routing-9 on image store 3, may request download based on available hypervisor types
> 36977 2013-07-26 10:19:17,735 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Removing leftover template routing-9 entry from template store table
> 36978 2013-07-26 10:19:17,745 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Template Sync did not find routing-10 on image store 3, may request download based on available hypervisor types
> 36979 2013-07-26 10:19:17,746 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Removing leftover template routing-10 entry from template store table
> 36980 2013-07-26 10:19:17,755 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Downloading template centos56-x86_64-xen to image store secondary2
> 36981 2013-07-26 10:19:17,793 DEBUG [storage.image.TemplateDataFactoryImpl] (AgentConnectTaskPool-5:null) template 5 is already in store:3, type:Image
> 36982 2013-07-26 10:19:17,842 DEBUG [storage.image.BaseImageStoreDriverImpl] (AgentConnectTaskPool-5:null) Downloading template to data store 3
> 36983 2013-07-26 10:19:17,882 DEBUG [storage.image.BaseImageStoreDriverImpl] (AgentConnectTaskPool-5:null) Performing image store createTemplate async callback
> 36984 2013-07-26 10:19:17,910 DEBUG [cloudstack.storage.RemoteHostEndPoint] (AgentConnectTaskPool-5:null) Sending command org.apache.cloudstack.storage.command.DownloadCommand to host: 6
> 36985 2013-07-26 10:19:17,926 DEBUG [agent.transport.Request] (AgentConnectTaskPool-5:null) Seq 6-1226899462: Sending { Cmd , MgmtId: 7280707764394, via: 6, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DownloadCommand":{"hvm":false,"description":" CentOS 5.6(64-bit) no GUI (XenServer)","checksum":"905cec879afd9c9d22ecc8036131a180","maxDownloadSizeInBytes":53687091200,"id":5,"resourceType":"TEMPLATE","installPath":"template/tmpl/1/5","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/expor t/home/swamy/secondary.campo.xen.1","_role":"Image"}},"url":"http://10.147.28.7/templates/builtin/centos56-x86_64.vhd.bz2","format":"VHD","accountId":1,"name":"centos56-x86_64-xen","secUrl":"nfs://10.147.28.7/export/home/swamy/secondary.campo.xen.1","wait":0}}] }
> (d.) It successfully downloaded Centos for zone2.
> 37167 2013-07-26 10:21:32,577 DEBUG [agent.transport.Request] (AgentManager-Handler-12:null) Seq 6-1226899473: Processing: { Ans: , MgmtId: 7280707764394, via: 6, Ver: v1, Flags: 10, [{"com.cloud.agent.api.storage.DownloadAnswer":{"jobId":"ed2afd45-561b-4116-a1a5-f8d dad687b12","downloadPct":100,"errorString":"Install completed successfully at 7/26/13 4:51 AM","downloadStatus":"DOWNLOADED","downloadPath":"/mnt/SecStorage/b814c66e-9d67-3f4a-bf26-51e9c8a20324/template/tmpl/1/5/dnld1552778138062074368tmp_","installPath":"templa te/tmpl/1/5/16ee261c-6992-3f95-9c81-14073a9cef61.vhd","templateSize":21474836480,"templatePhySicalSize":1758786048,"checkSum":"905cec879afd9c9d22ecc8036131a180","result":true,"details":"Install completed successfully at 7/26/13 4:51 AM","wait":0}}] }
> 37513 2013-07-26 10:24:30,410 INFO [context.support.XmlWebApplicationContext] (main:null) Bean 'actionEventInterceptor' of type [class com.cloud.event.ActionEventInterceptor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible f or auto-proxying)
> (e) At this moment, I found both my system vms in zone2 (s-9-VM and v-8-VM) up and running.
> (f) Installed usage server on the same machine and restarted management server after this.
> (g) Tried to deploy User VM on Zone2 and it failed with the following error.
> com.cloud.utils.exception.CloudRuntimeException: Template 1 has not been completely downloaded to zone 2
> at com.cloud.template.TemplateManagerImpl.getTemplateSize(TemplateManagerImpl.java:1648)
> at com.cloud.storage.VolumeManagerImpl.allocateTemplatedVolume(VolumeManagerImpl.java:1451)
> at com.cloud.vm.VirtualMachineManagerImpl.allocate(VirtualMachineManagerImpl.java:389)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.vm.VirtualMachineManagerImpl.allocate(VirtualMachineManagerImpl.java:417)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployRouter(VirtualNetworkApplianceManagerImpl.java:1648)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.findOrDeployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1548)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.deployVirtualRouterInGuestNetwork(VirtualNetworkApplianceManagerImpl.java:1946)
> at com.cloud.network.element.VirtualRouterElement.implement(VirtualRouterElement.java:203)
> (h) At this moment, verified the cloud.template_store_ref and found that "template 1" is not present.
> mysql> select * from template_store_ref where template_id=1;
> Empty set (0.00 sec)
> (i) Tried to restart SSVM to see what happens when it issues template sync. here is the snippet for the same.
> 39047 2013-07-26 10:25:27,933 DEBUG [agent.transport.Request] (AgentConnectTaskPool-5:null) Seq 6-341835782: Sending { Cmd , MgmtId: 7280707764394, via: 6, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.storage.ListTemplateCommand":{"store":{"com.cloud.agent.api.to.N fsTO":{"_url":"nfs://10.147.28.7/export/home/swamy/secondary.campo.xen.1","_role":"Image"}},"wait":0}}] }
> 39048 2013-07-26 10:25:27,936 DEBUG [xen.resource.CitrixResourceBase] (AgentTaskPool-1:null) Found a network called Pool-wide network associated with eth0 on host=10.147.40.31; Network=d9e8cc59-cdef-6ed9-6bc7-82b92d0be44c; pif=c33fec9b-70a8-04d4-21e9-8a6a48a6b0c3
> 39049 2013-07-26 10:25:27,936 INFO [xen.resource.CitrixResourceBase] (AgentTaskPool-1:null) Private Network is Pool-wide network associated with eth0 for host 10.147.40.31
> 39050 2013-07-26 10:25:27,937 INFO [xen.resource.CitrixResourceBase] (AgentTaskPool-1:null) Guest Network is Pool-wide network associated with eth0 for host 10.147.40.31
> 39051 2013-07-26 10:25:27,937 INFO [xen.resource.CitrixResourceBase] (AgentTaskPool-1:null) Public Network is Pool-wide network associated with eth0 for host 10.147.40.31
> 39052 2013-07-26 10:25:28,016 DEBUG [agent.transport.Request] (AgentManager-Handler-11:null) Seq 6-341835782: Processing: { Ans: , MgmtId: 7280707764394, via: 6, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.ListTemplateAnswer":{"secUrl":"nfs://10.147.28.7/expo rt/home/swamy/secondary.campo.xen.1","templateInfos":{"centos56-x86_64-xen":{"templateName":"centos56-x86_64-xen","installPath":"template/tmpl/1/5/16ee261c-6992-3f95-9c81-14073a9cef61.vhd","size":21474836480,"physicalSize":1758786048,"id":5,"isPublic":true,"isCo rrupted":false}},"result":true,"details":"success","wait":0}}] }
> 39053 2013-07-26 10:25:28,016 DEBUG [agent.transport.Request] (AgentConnectTaskPool-5:null) Seq 6-341835782: Received: { Ans: , MgmtId: 7280707764394, via: 6, Ver: v1, Flags: 110, { ListTemplateAnswer } }
> 39054 2013-07-26 10:25:28,017 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-11:null) Seq 6-341835782: No more commands found
> 39055 2013-07-26 10:25:28,031 DEBUG [xen.resource.CitrixResourceBase] (AgentTaskPool-1:null) Total Ram: 16190133120 dom0 Ram: 588251136
> 39056 2013-07-26 10:25:28,262 INFO [storage.image.TemplateServiceImpl] (AgentConnectTaskPool-5:null) Template Sync found centos56-x86_64-xen already in the image store
> (j) Destroyed SSVM and then didn't see any new SSVM coming up in zone2 forever. Snippet that talks about this is :
> 2013-07-26 11:55:47,525 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
> 2013-07-26 11:55:47,550 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) No secondary storage available in zone 2, wait until it is ready to launch secondary storage vm
> 2013-07-26 11:55:47,550 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 2 is not ready to launch secondary storage VM yet
> 2013-07-26 11:55:47,978 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> 2013-07-26 11:55:47,994 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone host is ready, but console proxy template: 1 is not ready on secondary storage.
--
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