cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "venkata swamybabu budumuru (JIRA)" <j...@apache.org>
Subject [jira] [Closed] (CLOUDSTACK-3845) [SystemVMTemplate] Unable to deploy router VM due to "Template 1 has not been completely downloaded to zone 2"
Date Mon, 29 Jul 2013 09:13:48 GMT

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

venkata swamybabu budumuru closed CLOUDSTACK-3845.
--------------------------------------------------

    
> [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
>            Assignee: Nitin Mehta
>            Priority: Critical
>             Fix For: 4.2.0
>
>         Attachments: logs.tgz, logs.tgz
>
>
> 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

Mime
View raw message