You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sanjeev N (JIRA)" <ji...@apache.org> on 2013/07/25 13:03:49 UTC

[jira] [Created] (CLOUDSTACK-3805) [object_store_Refactor] prepareTemplate cmd destroys the template from primary at the end of prepareTemplate process

Sanjeev N created CLOUDSTACK-3805:
-------------------------------------

             Summary: [object_store_Refactor] prepareTemplate cmd destroys the template from primary at the end of prepareTemplate process
                 Key: CLOUDSTACK-3805
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3805
             Project: CloudStack
          Issue Type: Bug
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: Storage Controller, Template
    Affects Versions: 4.2.0
         Environment: Latest build from ACS 4.2 branch.
Storage: NFS for both primary and secondary
Cluster: Xen
            Reporter: Sanjeev N
            Priority: Critical
             Fix For: 4.2.0


[object_store_Refactor] prepareTemplate cmd destroys the template from primary at the end of prepareTemplate process.

When prepare template command was executed, an entry was made in template_spool_ref table with state as "Creatin". After copying the template from secondary to primary template was destroyed(removed) from the primary and template entry was also removed from the template_spool_ref table.

Steps to Reproduce:
===============
1.Bring up CS in advanced zone.
2.Create a xen cluster with two primary storages.
3.Register any cent os template to CS
4.When the template is in ready state, fire prepareTemplate API:
http://10.147.59.126:8096/client/api?command=prepareTemplate&templateid=b6e88731-9a28-4856-b640-9740bd142c2e&zoneid=5c5c0b8a-9d5a-4b95-8f13-b31058ffdb37

Observations:
===========
After issueing the above API,two entries were created in template_spool_ref table with two pool ids (pood_id 1&2 , there are the two primary storages added in the cluster) with state="Creating":
*************************** 5. row ***************************
            id: 11
       pool_id: 1
   template_id: 204
       created: 2013-07-25 10:03:54
  last_updated: NULL
        job_id: NULL
  download_pct: 0
download_state: NOT_DOWNLOADED
     error_str: NULL
    local_path: NULL
  install_path: NULL
 template_size: 0
 marked_for_gc: 0
         state: Creating
  update_count: 1
       updated: 2013-07-25 10:03:54
*************************** 6. row ***************************
            id: 12
       pool_id: 2
   template_id: 204
       created: 2013-07-25 10:03:54
  last_updated: NULL
        job_id: NULL
  download_pct: 0
download_state: NOT_DOWNLOADED
     error_str: NULL
    local_path: NULL
  install_path: NULL
 template_size: 0
 marked_for_gc: 0
         state: Creating
  update_count: 1
       updated: 2013-07-25 10:03:54
6 rows in set (0.00 sec)

ERROR:
No query specified

Even though there are two entries in the template_spool_ref table, template was copied to only one primary storage. 
When the State was in Creating state, I could see the template copy progress in primary storage(template size was increasing). 
After completing the template copy, immediately template was disappeared from the primary storage and entry from template_store_ref table was also deleted.

I see vdi_destroy command executin in SMlog and xensource log file on xenserver.

Here is the log snippet from management server log:
========================================
2013-07-25 06:03:53,996 INFO  [cloud.template.TemplateManagerImpl] (Template-Preloader-4:null) Start to preload template 204 into primary storage 2
2013-07-25 06:03:54,025 DEBUG [cloud.template.TemplateManagerImpl] (Template-Preloader-3:null) Downloading template 204 to pool 1
2013-07-25 06:03:54,028 DEBUG [cloud.template.TemplateManagerImpl] (Template-Preloader-4:null) Downloading template 204 to pool 2
2013-07-25 06:03:54,033 DEBUG [storage.image.TemplateDataFactoryImpl] (Template-Preloader-3:null) template 204 is already in store:1, type:Image
2013-07-25 06:03:54,037 DEBUG [storage.image.TemplateDataFactoryImpl] (Template-Preloader-4:null) template 204 is already in store:1, type:Image
2013-07-25 06:03:54,039 DEBUG [storage.datastore.PrimaryDataStoreImpl] (Template-Preloader-3:null) Not found (templateId: 204, poolId: 1) in template_spool_ref
2013-07-25 06:03:54,039 DEBUG [storage.datastore.PrimaryDataStoreImpl] (Template-Preloader-3:null) Persisting (templateId: 204, poolId: 1) to template_spool_ref
2013-07-25 06:03:54,042 DEBUG [storage.datastore.PrimaryDataStoreImpl] (Template-Preloader-4:null) Not found (templateId: 204, poolId: 2) in template_spool_ref
2013-07-25 06:03:54,042 DEBUG [storage.datastore.PrimaryDataStoreImpl] (Template-Preloader-4:null) Persisting (templateId: 204, poolId: 2) to template_spool_ref
2013-07-25 06:03:54,158 DEBUG [storage.image.TemplateDataFactoryImpl] (Template-Preloader-4:null) template 204 is already in store:2, type:Primary
2013-07-25 06:03:54,159 DEBUG [storage.image.TemplateDataFactoryImpl] (Template-Preloader-3:null) template 204 is already in store:1, type:Primary
2013-07-25 06:03:54,185 DEBUG [storage.motion.AncientDataMotionStrategy] (Template-Preloader-4:null) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type TEMPLATE
2013-07-25 06:03:54,191 DEBUG [storage.motion.AncientDataMotionStrategy] (Template-Preloader-3:null) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type TEMPLATE
2013-07-25 06:03:54,227 DEBUG [agent.transport.Request] (Template-Preloader-4:null) Seq 1-513676275: Sending  { Cmd , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/204/f6d220c1-efc4-3e14-90f5-92c77f111215.vhd","origUrl":"http://10.147.28.7/templates/CentOS5.3/CentOS5.3HVM.vhd","uuid":"b6e88731-9a28-4856-b640-9740bd142c2e","id":204,"format":"VHD","accountId":2,"checksum":"34b5f768be3fbcbfd96436a093e432e5","hvm":true,"displayText":"cent53","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_xen_os","_role":"Image"}},"name":"204-2-d126fab8-efcd-30c6-9f47-5f9c4999a41f"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://10.147.28.7/templates/CentOS5.3/CentOS5.3HVM.vhd","uuid":"b6e88731-9a28-4856-b640-9740bd142c2e","id":204,"format":"VHD","accountId":2,"checksum":"34b5f768be3fbcbfd96436a093e432e5","hvm":true,"displayText":"cent53","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"05820c30-2a0e-33f7-b358-cc9c08864e10","id":2,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/sanjeev/pri_xen_os2","port":2049}},"name":"204-2-d126fab8-efcd-30c6-9f47-5f9c4999a41f"}},"executeInSequence":false,"wait":10800}}] }
2013-07-25 06:03:54,229 DEBUG [agent.transport.Request] (Template-Preloader-4:null) Seq 1-513676275: Executing:  { Cmd , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/204/f6d220c1-efc4-3e14-90f5-92c77f111215.vhd","origUrl":"http://10.147.28.7/templates/CentOS5.3/CentOS5.3HVM.vhd","uuid":"b6e88731-9a28-4856-b640-9740bd142c2e","id":204,"format":"VHD","accountId":2,"checksum":"34b5f768be3fbcbfd96436a093e432e5","hvm":true,"displayText":"cent53","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_xen_os","_role":"Image"}},"name":"204-2-d126fab8-efcd-30c6-9f47-5f9c4999a41f"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://10.147.28.7/templates/CentOS5.3/CentOS5.3HVM.vhd","uuid":"b6e88731-9a28-4856-b640-9740bd142c2e","id":204,"format":"VHD","accountId":2,"checksum":"34b5f768be3fbcbfd96436a093e432e5","hvm":true,"displayText":"cent53","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"05820c30-2a0e-33f7-b358-cc9c08864e10","id":2,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/sanjeev/pri_xen_os2","port":2049}},"name":"204-2-d126fab8-efcd-30c6-9f47-5f9c4999a41f"}},"executeInSequence":false,"wait":10800}}] }
2013-07-25 06:03:54,230 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-393:null) Seq 1-513676275: Executing request
2013-07-25 06:03:54,242 DEBUG [agent.transport.Request] (Template-Preloader-3:null) Seq 1-513676276: Sending  { Cmd , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/204/f6d220c1-efc4-3e14-90f5-92c77f111215.vhd","origUrl":"http://10.147.28.7/templates/CentOS5.3/CentOS5.3HVM.vhd","uuid":"b6e88731-9a28-4856-b640-9740bd142c2e","id":204,"format":"VHD","accountId":2,"checksum":"34b5f768be3fbcbfd96436a093e432e5","hvm":true,"displayText":"cent53","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_xen_os","_role":"Image"}},"name":"204-2-d126fab8-efcd-30c6-9f47-5f9c4999a41f"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://10.147.28.7/templates/CentOS5.3/CentOS5.3HVM.vhd","uuid":"b6e88731-9a28-4856-b640-9740bd142c2e","id":204,"format":"VHD","accountId":2,"checksum":"34b5f768be3fbcbfd96436a093e432e5","hvm":true,"displayText":"cent53","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"c65a038a-750c-3b4f-bf26-7ce3b74e1c85","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/sanjeev/pri_xen_os","port":2049}},"name":"204-2-d126fab8-efcd-30c6-9f47-5f9c4999a41f"}},"executeInSequence":false,"wait":10800}}] }
2013-07-25 06:03:54,245 DEBUG [agent.transport.Request] (Template-Preloader-3:null) Seq 1-513676276: Executing:  { Cmd , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/204/f6d220c1-efc4-3e14-90f5-92c77f111215.vhd","origUrl":"http://10.147.28.7/templates/CentOS5.3/CentOS5.3HVM.vhd","uuid":"b6e88731-9a28-4856-b640-9740bd142c2e","id":204,"format":"VHD","accountId":2,"checksum":"34b5f768be3fbcbfd96436a093e432e5","hvm":true,"displayText":"cent53","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_xen_os","_role":"Image"}},"name":"204-2-d126fab8-efcd-30c6-9f47-5f9c4999a41f"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://10.147.28.7/templates/CentOS5.3/CentOS5.3HVM.vhd","uuid":"b6e88731-9a28-4856-b640-9740bd142c2e","id":204,"format":"VHD","accountId":2,"checksum":"34b5f768be3fbcbfd96436a093e432e5","hvm":true,"displayText":"cent53","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"c65a038a-750c-3b4f-bf26-7ce3b74e1c85","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/sanjeev/pri_xen_os","port":2049}},"name":"204-2-d126fab8-efcd-30c6-9f47-5f9c4999a41f"}},"executeInSequence":false,"wait":10800}}] }
2013-07-25 06:25:17,421 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-393:null) Seq 1-513676275: Response Received:
2013-07-25 06:25:17,421 DEBUG [agent.transport.Request] (DirectAgent-393:null) Seq 1-513676275: Processing:  { Ans: , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"c94e51ae-a5e0-4be0-b212-a700525ae9af","uuid":"c94e51ae-a5e0-4be0-b212-a700525ae9af","id":0,"format":"VHD","accountId":0,"hvm":false}},"result":true,"wait":0}}] }
2013-07-25 06:25:17,562 INFO  [cloud.template.TemplateManagerImpl] (Template-Preloader-4:null) End of preloading template 204 into primary storage 2

Log snippet from SMlog:
===================
[root@Rack1Pod1Host14 ~]# zgrep -i 8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85 /var/log/SMlog*
/var/log/SMlog:[26826] 2013-07-25 10:03:53.105185       ['/usr/sbin/td-util', 'create', 'vhd', '20480', '/var/run/sr-mount/d014bd96-e7d8-c7b8-de19-6a916bd2d308/8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85.vhd']
/var/log/SMlog:[26826] 2013-07-25 10:03:53.372981       ['/usr/sbin/td-util', 'query', 'vhd', '-v', '/var/run/sr-mount/d014bd96-e7d8-c7b8-de19-6a916bd2d308/8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85.vhd']
/var/log/SMlog:[26981] 2013-07-25 10:04:30.081270       VDIs changed on disk: ['e46a9134-de42-4e33-81f4-b5aa9190aa2c', '8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85']
[root@Rack1Pod1Host14 ~]# zgrep -i 8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85 /var/log/SMlog*
/var/log/SMlog:[26826] 2013-07-25 10:03:53.105185       ['/usr/sbin/td-util', 'create', 'vhd', '20480', '/var/run/sr-mount/d014bd96-e7d8-c7b8-de19-6a916bd2d308/8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85.vhd']
/var/log/SMlog:[26826] 2013-07-25 10:03:53.372981       ['/usr/sbin/td-util', 'query', 'vhd', '-v', '/var/run/sr-mount/d014bd96-e7d8-c7b8-de19-6a916bd2d308/8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85.vhd']
/var/log/SMlog:[26981] 2013-07-25 10:04:30.081270       VDIs changed on disk: ['e46a9134-de42-4e33-81f4-b5aa9190aa2c', '8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85']
/var/log/SMlog:[2096] 2013-07-25 10:24:56.184399        vdi_delete {'sr_uuid': 'd014bd96-e7d8-c7b8-de19-6a916bd2d308', 'subtask_of': 'DummyRef:|04ddc78e-25a7-e50a-248b-1d81d9a40fa0|VDI.destroy', 'vdi_ref': 'OpaqueRef:59f2abcf-aa29-d3ab-c9d0-590ce3e749de', 'vdi_on_boot': 'persist', 'args': [], 'vdi_location': '8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85', 'host_ref': 'OpaqueRef:ed811e29-954f-d12e-291b-002885716796', 'session_ref': 'OpaqueRef:3ce255d4-a5ca-e3f7-e248-2b175fe85d7b', 'device_config': {'SRmaster': 'true', 'serverpath': '/export/home/sanjeev/pri_xen_os', 'server': '10.147.28.7'}, 'command': 'vdi_delete', 'vdi_allow_caching': 'false', 'sr_ref': 'OpaqueRef:2ba7d8d2-7ce5-0ba1-dab3-c3f7e70705d3', 'vdi_uuid': '8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85'}
/var/log/SMlog:[2096] 2013-07-25 10:24:56.194862        ['/usr/bin/vhd-util', 'set', '--debug', '-n', '/var/run/sr-mount/d014bd96-e7d8-c7b8-de19-6a916bd2d308/8c632f6f-0d76-4ac4-a0d6-cc8433d8bd85.vhd', '-f', 'hidden', '-v', '1']







--
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