You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cloudstack.apache.org by GitBox <gi...@apache.org> on 2020/04/06 18:43:46 UTC

[GitHub] [cloudstack] andrijapanicsb opened a new issue #4018: Snapshots GC from DB - needs refractoring and fixing snapshot_store_ref garbage

andrijapanicsb opened a new issue #4018: Snapshots GC from DB - needs refractoring and fixing snapshot_store_ref garbage
URL: https://github.com/apache/cloudstack/issues/4018
 
 
   For details please see my comment: https://github.com/apache/cloudstack/pull/3969#issuecomment-609950065
   
   The idea is that when the GC kicks in (setting storage.cleanup.interval) - it will remove SOME rows from the snapshot_store_ref table (IMAGE rows, where role_type=image) but not the PRIMARY (role_type=primary) and thus the garbage is left in the snapshot_stor_ref table.
   
   In the comment ^^^ I have explained in details what fields in DB tables are changed when deleting a snap, vs when GC kicks in, etc. 
   
   Reproduce the issue:
   
   - set storage.cleanup.interval=60 (seconds),
   - set snapshot.backup.to.secondary=true, 
   - spin a VM (1 or more volumes), any hypervisor
   - create snapshots
   - delete snapshots
   - wait for GC to kicks in:    tail -f /var/log/cloudstack/management/management-server.log | grep "StorageManager-Scavenger"   
   - check the snapshot_store_ref table - rows are left where role_type=primary

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services

[GitHub] [cloudstack] andrijapanicsb edited a comment on issue #4018: Snapshots GC from DB - needs refractoring and fixing snapshot_store_ref garbage

Posted by GitBox <gi...@apache.org>.
andrijapanicsb edited a comment on issue #4018: Snapshots GC from DB - needs refractoring and fixing snapshot_store_ref garbage
URL: https://github.com/apache/cloudstack/issues/4018#issuecomment-611628944
 
 
   XenServer removes previous snapshots from the "primary storage" when a new one is created - it does NOT delete it really, but deletes the PRIMARY row in the snap_store_ref table, thus the garbage is left on Primary Store while the reference is deleted from the snap_store_ref - and later GC is not picking it up as the row/reference is not there....  Stupid implementation by all means:
   
   
   [root@ref-trl-774-k-M7-apanic-mgmt1 ~]# grep 301a4ad6 /var/log/cloudstack/management/management-server.log | grep -v "queryAsyncJobResult"
   2020-04-09 16:29:45,717 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592) (logid:301a4ad6) Executing AsyncJobVO {id:592, userId: 2, accountId: 2, instanceType: Snapshot, instanceId: 85, cmd: org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: {"quiescevm":"false","httpmethod":"GET","ctxAccountId":"2","uuid":"ba2df407-1772-4668-9327-026af717dbce","cmdEventType":"SNAPSHOT.CREATE","asyncBackup":"false","response":"json","ctxUserId":"2","volumeId":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","name":"snap4","ctxStartEventId":"1274","id":"85","ctxDetails":"{\"interface com.cloud.storage.Snapshot\":\"ba2df407-1772-4668-9327-026af717dbce\",\"interface com.cloud.storage.Volume\":\"05c88236-1aa6-44c3-9bf9-bad4edfc34e5\"}","_":"1586449031328"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
   32988805007466, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null}
   2020-04-09 16:29:45,743 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Sync job-593 execution on object VmWorkJobQueue.22
   2020-04-09 16:29:47,735 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Executing AsyncJobVO {id:593, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAAZaAAthc3luY0JhY2t1cFoACXF1aWVzY2VWbUwADGxvY2F0aW9uVHlwZXQAKUxjb20vY2xvdWQvc3RvcmFnZS9TbmFwc2hvdCRMb2NhdGlvblR5cGU7TAAIcG9saWN5SWR0ABBMamF2YS9sYW5nL0xvbmc7TAAKc25hcHNob3RJZHEAfgACTAAIdm9sdW1lSWRxAH4AAnhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAFnQAFFZvbHVtZUFwaVNlcnZpY2VJbXBsAABwc3IADmphdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAAAAAAAAAc3EAfgAHAAAAAAAAAFVzcQB-AAcAAAAAAAAANg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 32988805007466, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Apr 09 16:29:45 UTC 2020, removed: null}
   2020-04-09 16:29:47,736 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Run VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 22, job origin: 592
   2020-04-09 16:29:47,737 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Execute VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":54,"policyId":0,"snapshotId":85,"quiesceVm":false,"asyncBackup":false,"userId":2,"accountId":2,"vmId":22,"handlerName":"VolumeApiServiceImpl"}
   2020-04-09 16:29:47,775 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CreateObjectCommand
   2020-04-09 16:29:47,775 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) We are returning the default host to execute commands because the command is not of Copy
   type.
   2020-04-09 16:29:47,776 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682460: Sending  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"wait":0}}] }
   2020-04-09 16:29:47,776 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682460: Executing:  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"wait":0}}] }
   2020-04-09 16:29:50,193 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-39:ctx-5870584c) (logid:301a4ad6) Seq 2-5707749577738682460: Response Received:
   2020-04-09 16:29:50,193 DEBUG [c.c.a.t.Request] (DirectAgent-39:ctx-5870584c) (logid:301a4ad6) Seq 2-5707749577738682460: Processing:  { Ans: , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"ec235cfb-3e6e-40aa-9515-e6943b8e2241","id":0,"quiescevm":false,"physicalSize":0}},"result":true,"wait":0}}] }
   2020-04-09 16:29:50,193 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682460: Received:  { Ans: , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 10, { CreateObjectAnswer } }
   2020-04-09 16:29:50,254 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) copyAsync inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT
   2020-04-09 16:29:50,323 ERROR [o.a.c.s.e.DefaultEndPointSelector] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) IR24 select BACKUPSNAPSHOT from primary to secondary 85 dest=85
   2020-04-09 16:29:50,326 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CopyCommand
   2020-04-09 16:29:50,326 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) We are returning the default host to execute commands because the source and destination
   objects are not NFS type.
   2020-04-09 16:29:50,327 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682461: Sending  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"ec235cfb-3e6e-40aa-9515-e6943b8e2241","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/54","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"NFS://10.2.0.16/acs/secondary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-sec1","_role":"Image"}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["snapshots/2/54/14c13d66-53f4-4003-a284-cf266fe1ee3c.vhd","snapshots/2/54/151ca037-2b00-44a3-abb2-b212962b51be.vhd","snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd"],"physicalSize":0}},"executeInSequence":true,"options":{"fullSnapshot":"true"},"options2":{},"wait":21600}}] }
   2020-04-09 16:29:50,328 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682461: Executing:  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"ec235cfb-3e6e-40aa-9515-e6943b8e2241","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/54","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"NFS://10.2.0.16/acs/secondary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-sec1","_role":"Image"}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["snapshots/2/54/14c13d66-53f4-4003-a284-cf266fe1ee3c.vhd","snapshots/2/54/151ca037-2b00-44a3-abb2-b212962b51be.vhd","snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd"],"physicalSize":0}},"executeInSequence":true,"options":{"fullSnapshot":"true"},"options2":{},"wait":21600}}] }
   2020-04-09 16:29:52,641 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) No file SR found for path: /var/cloud_mount/569d499d-d7f7-31d4-b124-baf0ad97e161/snapshots/2/54
   2020-04-09 16:29:52,641 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Creating file SR for path [/var/cloud_mount/569d499d-d7f7-31d4-b124-baf0ad97e161/snapshots/2/54] on host [fb4b5939-8702-46b7-bb02-7f43ab6bb9b8]
   2020-04-09 16:30:04,285 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:3d230637-af2f-e354-2db8-e0fccbe62d2b: Removing SR
   2020-04-09 16:30:04,325 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:d3f62ef8-cbbf-3d41-f4bd-c8fb4252adaa: Unplugging pbd
   2020-04-09 16:30:04,651 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:3d230637-af2f-e354-2db8-e0fccbe62d2b: Forgetting
   **2020-04-09 16:30:04,667 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Successfully destroyed snapshot on volume: dd772879-f006-41ec-b09e-db5699f7a7fb execept this current snapshot ec235cfb-3e6e-40aa-9515-e6943b8e2241
   2020-04-09 16:30:04,667 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) New snapshot details: SnapshotTO[datastore=null|volume=null|pathsnapshots/2/54/d4e824b5-f9ac-469f-b94f-dbdf39e8b682.vhd]**
   2020-04-09 16:30:04,667 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) New snapshot physical utilization: 67244544
   2020-04-09 16:30:04,668 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Seq 2-5707749577738682461: Response Received:
   2020-04-09 16:30:04,668 DEBUG [c.c.a.t.Request] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Seq 2-5707749577738682461: Processing:  { Ans: , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/54/d4e824b5-f9ac-469f-b94f-dbdf39e8b682.vhd","id":0,"quiescevm":false,"physicalSize":67244544}},"result":true,"wait":0}}] }
   2020-04-09 16:30:04,668 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Seq 2-5707749577738682461: No more commands found
   2020-04-09 16:30:04,668 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682461: Received:  { Ans: , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 110, { CopyCmdAnswer } }
   2020-04-09 16:30:04,690 DEBUG [c.c.r.ResourceLimitManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Updating resource Type = secondary_storage count for Account = 2 Operation = decreasing Amount = 1006497280
   2020-04-09 16:30:04,694 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Done executing VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":54,"policyId":0,"snapshotId":85,"quiesceVm":false,"asyncBackup":false,"userId":2,"accountId":2,"vmId":22,"handlerName":"VolumeApiServiceImpl"}
   2020-04-09 16:30:04,694 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Complete async job-593, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAAVQ
   2020-04-09 16:30:04,695 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Publish async job-593 complete on message bus
   2020-04-09 16:30:04,695 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Wake up jobs related to job-593
   2020-04-09 16:30:04,695 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Update db status for job-593
   2020-04-09 16:30:04,696 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Wake up jobs joined with job-593 and disjoin all subjobs created from job- 593
   2020-04-09 16:30:04,702 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Done with run of VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 22, job origin: 592
   2020-04-09 16:30:04,702 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Done executing com.cloud.vm.VmWorkTakeVolumeSnapshot for job-593
   2020-04-09 16:30:04,705 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Remove job-593 from job monitoring
   2020-04-09 16:30:04,720 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Complete async job-592, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SnapshotResponse/snapshot/{"id":"ba2df407-1772-4668-9327-026af717dbce","account":"admin","domainid":"887f0da6-72a9-11ea-9abc-1e00ce01086a","domain":"ROOT","snapshottype":"MANUAL","volumeid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumename":"xen-data-1","volumetype":"DATADISK","created":"2020-04-09T16:29:45+0000","name":"snap4","intervaltype":"MANUAL","state":"BackedUp","physicalsize":67244544,"zoneid":"e5d78fcd-deb6-4316-9190-136bc788b265","revertable":false,"virtualsize":1073741824,"tags":[]}
   2020-04-09 16:30:04,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Publish async job-592 complete on message bus
   2020-04-09 16:30:04,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Wake up jobs related to job-592
   2020-04-09 16:30:04,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Update db status for job-592
   2020-04-09 16:30:04,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Wake up jobs joined with job-592 and disjoin all subjobs created from job- 592
   2020-04-09 16:30:04,725 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592) (logid:301a4ad6) Done executing org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-592
   2020-04-09 16:30:04,725 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-12:ctx-56cd28cc job-592) (logid:301a4ad6) Remove job-592 from job monitoring
   
   From XS snapshots, we can create template/volume:
   - In both cases (creating a template of a volume)  -  the existing folder holding the snaphosts on the Secondary Storage is mounted as a new SRs on XS host and template is created (again inside a new SR from a new folder where the template is put - previously created on the Sec Stor). For creating a volume out of a snap, just the existing Secondary Storage snap folder is mounted and whole image copied back to Primary Storage
   - i.e. we NEVER read original snap from the PRIMARY storage -  confirmed by manually deleteing all snaps of a volume and being able to create tempalte/volume from some snap.
   - i.e. we should really delete all older snaps (as it seems) when we create a new one, from the Primary Storage - and keep all snaps on Secondary Storage (like so far)

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services

[GitHub] [cloudstack] andrijapanicsb edited a comment on issue #4018: Snapshots GC from DB and XenServer Primary Storage garbage

Posted by GitBox <gi...@apache.org>.
andrijapanicsb edited a comment on issue #4018: Snapshots GC from DB and XenServer Primary Storage garbage
URL: https://github.com/apache/cloudstack/issues/4018#issuecomment-611693552
 
 
   Thinking aloud about the **correct workflow for different hypervisors,** after being busy with the snapshots issues on PR #3969  for 40+h...
   
   ### XS
   
   - XS snap issues: although we "try", we don't really delete older snaps when the current/new one when it's created - we should fix this, and then all older snaps are deleted from Primary and so are their references PRIMARY in snap_store_ref. 
   - We are chaining/making parent-child relation in snap_store_ref table ... Remove the relation? we are copying over FULL snaps from Primary to Secondary always and the snap is NEVER used from Primary storage in order to create new volume or new template.
   - Implement the same logic as for KVM/VMware - once the snap is Backed Up to Secondary Storage - remove it completely from the Primary Storage (this assumes snapshot.backup.to.secondary=FALSE continues to be NOT supported)
   
   ## VMware (current state)
   - VMware - when snapshots is created on Secondary Storage, nothing is left on Primary, although we leave the PRIMARY row in snap_Store_ref (i.e. should be removed)
   - Deleting the template will delete it on Secondary Storage immediately, and mark all snap_stor_ref -rows as DESTROYED, and same happens for snap row in the main snapshots table.
   - GC seems to be looking ONLY for IMAGE references rows in snap_store_ref table  - it's looking only for those in the DESTROYED state where the corresponding row in the main snapshots table does NOT have a "removed" date set. It seems (conclusion by testing...) that it does NOT look for (was not designed for?) to even look for PRIMARY references in snap_store_ref table, as the identical behaviour is observed for KVM  - so GC does remove the snap from Secondary Storage if not already removed (should be, unless SSVM was down when we deleted the snap via API/UI) and remove the IMAGE row from snap_store_ref
   - ^^^ One more reason that we "copy" the logic from XS, to remove the PRIMARY row when the new snap is created (copied to Secondary Storage) - so we only keep IMAGE rows when a new snap is created in snap_store_ref table
   
   ## KVM (current state)
   - KVM - identical stuff happens as with VMware ( i.e. PRIMARY row is left for whatever reason when snap is created, while there is NO snap on QCOW2 file - _but keep in mind that **when** NOT backing up to Sec Storage (works with KVM+Ceph only), then we do need/have the PRIMARY row_
   - as GC seems not designed to remove PRIMARY ref rows???, it's never removed... (GC does remove image from Secondary Storage if not deleted previously as it should (i.e. SSVM was down during snap deletion) and only removes the IMAGE ref row)
   
   
   We still do have a special case of "snapshot.backup.to.secondary=FALSE" which works for KVM+Ceph only and there we have only the PRIMARY row created in the first place... that seems to be working fine? (GC stuff, deletion in both cases when we backup or not to Secondary Storage

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services

[GitHub] [cloudstack] andrijapanicsb commented on issue #4018: Snapshots GC from DB - needs refractoring and fixing snapshot_store_ref garbage

Posted by GitBox <gi...@apache.org>.
andrijapanicsb commented on issue #4018: Snapshots GC from DB - needs refractoring and fixing snapshot_store_ref garbage
URL: https://github.com/apache/cloudstack/issues/4018#issuecomment-611693552
 
 
   Thinking aloud about the **correct workflow for different hypervisors,** after being busy with the snapshots issues on PR #3969  for 40+h...
   
   ### XS
   
   - XS snap issues: although we "try", we don't really delete older snaps than the current/new one when it's created - we should fix this, and then all older snaps are deleted from Primary and so are their references PRIMARY in snap_store_ref. We are chaining, why are we chaining... We are copying over FULL snaps from Primary to Secondary anyways.....) 
   GC will pick up everything properly later (it does so in 4.13.1/4.14, as part of PR #3969 ) - and the issue of Primary Storage snap garbage for XS would be solved (testing with just creating one snap and deleting it is NOT valid - as the PRIMARY row from snap_store_ref is not deleted - it's deleted for PREVIOUS snaps, and the very first snap has NO previous snaps...
   - GC does remove the last snap (which does have PRIMARY reference in snap_store_ref) from the Primary Storage - so check that code, and implement in this createSnapshots where it supposedly deletes the older snaps...
   - previous snaps deletion failure (when new snap is created) - perhaps it's a race case where the PRIMARY row is first deleted and then code looks for references to delete on Primary Storage and since no references, nothing gets deleted...
   
   ## VMware (current state)
   - VMware - when snapshots is created on Secondary Storage, nothing is left on Primary, although we leave the PRIMARY row in snap_Store_ref.
   - Deleting the template will delete it on Secondary Storage immediately, and mark all snap_stor_ref -rows as DESTROYED, and same happens for snap row in the main snapshots table.
   - GC seems to be looking ONLY for IMAGE rows in snap_store_ref table  - it's looking only for those in the DESTROYED state where the corresponding row in the main snapshots table does NOT have a "removed" date set. It seems (conclusion by testing...) that it does NOT look for (was not designed for?) to even look for PRIMARY references in snap_store_ref table, as the identical behaviour is observed for KVM and XS GC stuff - so "remove from Secondary Storage if not already removed (should be, unless SSVM was down) and remove the IMAGE row from snap_store_ref"
   - ^^^ One more reason that we "copy" the logic from XS, to remove the PRIMARY row when the new snap is created (copied to Secondary Storage) - so we only keep IMAGE rows when snap is created in snap_store_ref table
   
   ## KVM (current state)
   - KVM - identical stuff happens as with VMware ( i.e. PRIMARY row is left for whatever reason when snap is created, while there is NO snap on QCOW2 file - _but keep in mind that when NOT backing up to Sec Storage (works with KVM+Ceph only), then we do need/have the PRIMARY row_
   - as GC seems not designed to remove PRIMARY ref rows???, it's never removed... (GC does remove image from Secondary Storage if not deleted previously as it should (i.e. SSVM was down during snap deletion) and only removes the IMAGE ref row)
   
   
   We still do have a special case of "snapshot.backup.to.secondary=FALSE" which works for KVM+Ceph only and there we have only the PRIMARY row created in the first place... that seems to be working fine? (GC stuff, deletion in both cases when we backup or not to Secondary Storage

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services

[GitHub] [cloudstack] andrijapanicsb edited a comment on issue #4018: Snapshots GC from DB and XenServer Primary Storage garbage

Posted by GitBox <gi...@apache.org>.
andrijapanicsb edited a comment on issue #4018: Snapshots GC from DB and XenServer Primary Storage garbage
URL: https://github.com/apache/cloudstack/issues/4018#issuecomment-611628944
 
 
   Observation from logs:
   XenServer removes **previous** snapshots from the "primary storage" when a new one is created - it does NOT delete it really, but deletes the PRIMARY row in the snap_store_ref table, thus the garbage is left on Primary Store while the reference is deleted from the snap_store_ref - and later GC is not picking it up as the row/reference is not there....  Stupid implementation by all means:
   
   
   [root@ref-trl-774-k-M7-apanic-mgmt1 ~]# grep 301a4ad6 /var/log/cloudstack/management/management-server.log | grep -v "queryAsyncJobResult"
   2020-04-09 16:29:45,717 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592) (logid:301a4ad6) Executing AsyncJobVO {id:592, userId: 2, accountId: 2, instanceType: Snapshot, instanceId: 85, cmd: org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: {"quiescevm":"false","httpmethod":"GET","ctxAccountId":"2","uuid":"ba2df407-1772-4668-9327-026af717dbce","cmdEventType":"SNAPSHOT.CREATE","asyncBackup":"false","response":"json","ctxUserId":"2","volumeId":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","name":"snap4","ctxStartEventId":"1274","id":"85","ctxDetails":"{\"interface com.cloud.storage.Snapshot\":\"ba2df407-1772-4668-9327-026af717dbce\",\"interface com.cloud.storage.Volume\":\"05c88236-1aa6-44c3-9bf9-bad4edfc34e5\"}","_":"1586449031328"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
   32988805007466, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null}
   2020-04-09 16:29:45,743 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Sync job-593 execution on object VmWorkJobQueue.22
   ...
   ...
   2020-04-09 16:29:50,328 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682461: Executing:  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"ec235cfb-3e6e-40aa-9515-e6943b8e2241","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/54","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}}"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"NFS://10.2.0.16/acs/secondary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-sec1","_role":"Image"}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["snapshots/2/54/14c13d66-53f4-4003-a284-cf266fe1ee3c.vhd","snapshots/2/54/151ca037-2b00-44a3-abb2-b212962b51be.vhd","snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd"],"physicalSize":0}},"executeInSequence":true,"options": ...
   **{"fullSnapshot":"true"},"options2":{},"wait":21600}}] }**
   
   2020-04-09 16:29:52,641 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) No file SR found for path: /var/cloud_mount/569d499d-d7f7-31d4-b124-baf0ad97e161/snapshots/2/54
   2020-04-09 16:29:52,641 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Creating file SR for path [/var/cloud_mount/569d499d-d7f7-31d4-b124-baf0ad97e161/snapshots/2/54] on host [fb4b5939-8702-46b7-bb02-7f43ab6bb9b8]
   2020-04-09 16:30:04,285 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:3d230637-af2f-e354-2db8-e0fccbe62d2b: Removing SR
   2020-04-09 16:30:04,325 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:d3f62ef8-cbbf-3d41-f4bd-c8fb4252adaa: Unplugging pbd
   2020-04-09 16:30:04,651 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:3d230637-af2f-e354-2db8-e0fccbe62d2b: Forgetting
   
   
   **2020-04-09 16:30:04,667 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Successfully destroyed snapshot on volume: dd772879-f006-41ec-b09e-db5699f7a7fb execept this current snapshot ec235cfb-3e6e-40aa-9515-e6943b8e2241
   2020-04-09 16:30:04,667 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) New snapshot details: SnapshotTO[datastore=null|volume=null|pathsnapshots/2/54/d4e824b5-f9ac-469f-b94f-dbdf39e8b682.vhd]**
   ...
   ...
   
   
   From XS snapshots, we can create template/volume:
   - In both cases (creating a template of a volume)  -  the existing folder holding the snaphosts on the Secondary Storage is mounted as a new SRs on XS host and template is created (again inside a new SR from a new folder where the template is put - previously created on the Sec Stor). For creating a volume out of a snap, just the existing Secondary Storage snap folder is mounted and whole image copied back to Primary Storage
   - i.e. we NEVER read original snap from the PRIMARY storage -  confirmed by manually deleting all snaps of a volume and being able to create tempalte/volume from some snap.
   - i.e. we should really delete all older snaps (as it seems) when we create a new one, from the Primary Storage - and keep all snaps on Secondary Storage (like so far)

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services

[GitHub] [cloudstack] andrijapanicsb edited a comment on issue #4018: Snapshots GC from DB and XenServer Primary Storage garbage

Posted by GitBox <gi...@apache.org>.
andrijapanicsb edited a comment on issue #4018: Snapshots GC from DB and XenServer Primary Storage garbage
URL: https://github.com/apache/cloudstack/issues/4018#issuecomment-611693552
 
 
   Thinking aloud about the **correct workflow for different hypervisors,** after being busy with the snapshots issues on PR #3969  for 40+h...
   
   ### XS
   
   - XS snap issues: although we "try", we don't really delete older snaps than the current/new one when it's created - we should fix this, and then all older snaps are deleted from Primary and so are their references PRIMARY in snap_store_ref. We are chaining, why are we chaining... We are copying over FULL snaps from Primary to Secondary anyways.....) and the snap is NEVER used from Primary storage in order to create new volume or new template.
   - Implement the same logic as for KVM/VMware - once the snap is Backed Up to Secondary Storage - remove it completely from the Primary Storage (
   
   ## VMware (current state)
   - VMware - when snapshots is created on Secondary Storage, nothing is left on Primary, although we leave the PRIMARY row in snap_Store_ref.
   - Deleting the template will delete it on Secondary Storage immediately, and mark all snap_stor_ref -rows as DESTROYED, and same happens for snap row in the main snapshots table.
   - GC seems to be looking ONLY for IMAGE references rows in snap_store_ref table  - it's looking only for those in the DESTROYED state where the corresponding row in the main snapshots table does NOT have a "removed" date set. It seems (conclusion by testing...) that it does NOT look for (was not designed for?) to even look for PRIMARY references in snap_store_ref table, as the identical behaviour is observed for KVM  - so GC does remove the snap from Secondary Storage if not already removed (should be, unless SSVM was down when we deleted the snap via API/UI) and remove the IMAGE row from snap_store_ref
   - ^^^ One more reason that we "copy" the logic from XS, to remove the PRIMARY row when the new snap is created (copied to Secondary Storage) - so we only keep IMAGE rows when a new snap is created in snap_store_ref table
   
   ## KVM (current state)
   - KVM - identical stuff happens as with VMware ( i.e. PRIMARY row is left for whatever reason when snap is created, while there is NO snap on QCOW2 file - _but keep in mind that **when** NOT backing up to Sec Storage (works with KVM+Ceph only), then we do need/have the PRIMARY row_
   - as GC seems not designed to remove PRIMARY ref rows???, it's never removed... (GC does remove image from Secondary Storage if not deleted previously as it should (i.e. SSVM was down during snap deletion) and only removes the IMAGE ref row)
   
   
   We still do have a special case of "snapshot.backup.to.secondary=FALSE" which works for KVM+Ceph only and there we have only the PRIMARY row created in the first place... that seems to be working fine? (GC stuff, deletion in both cases when we backup or not to Secondary Storage

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services

[GitHub] [cloudstack] andrijapanicsb commented on issue #4018: Snapshots GC from DB - needs refractoring and fixing snapshot_store_ref garbage

Posted by GitBox <gi...@apache.org>.
andrijapanicsb commented on issue #4018: Snapshots GC from DB - needs refractoring and fixing snapshot_store_ref garbage
URL: https://github.com/apache/cloudstack/issues/4018#issuecomment-611628944
 
 
   XenServer removes previous snapshots from the "primary storage" when a new one is created - it does NOT delete it really, but deletes the PRIMARY row in the snap_store_ref table, thus the garbage is left on Primary Store while the reference is deleted from the snap_store_ref - and later GC is not picking it up as the row/reference is not there....  Stupid implementation by all means:
   
   
   [root@ref-trl-774-k-M7-apanic-mgmt1 ~]# grep 301a4ad6 /var/log/cloudstack/management/management-server.log | grep -v "queryAsyncJobResult"
   2020-04-09 16:29:45,717 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592) (logid:301a4ad6) Executing AsyncJobVO {id:592, userId: 2, accountId: 2, instanceType: Snapshot, instanceId: 85, cmd: org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: {"quiescevm":"false","httpmethod":"GET","ctxAccountId":"2","uuid":"ba2df407-1772-4668-9327-026af717dbce","cmdEventType":"SNAPSHOT.CREATE","asyncBackup":"false","response":"json","ctxUserId":"2","volumeId":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","name":"snap4","ctxStartEventId":"1274","id":"85","ctxDetails":"{\"interface com.cloud.storage.Snapshot\":\"ba2df407-1772-4668-9327-026af717dbce\",\"interface com.cloud.storage.Volume\":\"05c88236-1aa6-44c3-9bf9-bad4edfc34e5\"}","_":"1586449031328"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid:
   32988805007466, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null}
   2020-04-09 16:29:45,743 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Sync job-593 execution on object VmWorkJobQueue.22
   2020-04-09 16:29:47,735 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Executing AsyncJobVO {id:593, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAAZaAAthc3luY0JhY2t1cFoACXF1aWVzY2VWbUwADGxvY2F0aW9uVHlwZXQAKUxjb20vY2xvdWQvc3RvcmFnZS9TbmFwc2hvdCRMb2NhdGlvblR5cGU7TAAIcG9saWN5SWR0ABBMamF2YS9sYW5nL0xvbmc7TAAKc25hcHNob3RJZHEAfgACTAAIdm9sdW1lSWRxAH4AAnhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAFnQAFFZvbHVtZUFwaVNlcnZpY2VJbXBsAABwc3IADmphdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAAAAAAAAAc3EAfgAHAAAAAAAAAFVzcQB-AAcAAAAAAAAANg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 32988805007466, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Apr 09 16:29:45 UTC 2020, removed: null}
   2020-04-09 16:29:47,736 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Run VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 22, job origin: 592
   2020-04-09 16:29:47,737 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Execute VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":54,"policyId":0,"snapshotId":85,"quiesceVm":false,"asyncBackup":false,"userId":2,"accountId":2,"vmId":22,"handlerName":"VolumeApiServiceImpl"}
   2020-04-09 16:29:47,775 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CreateObjectCommand
   2020-04-09 16:29:47,775 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) We are returning the default host to execute commands because the command is not of Copy
   type.
   2020-04-09 16:29:47,776 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682460: Sending  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"wait":0}}] }
   2020-04-09 16:29:47,776 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682460: Executing:  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"wait":0}}] }
   2020-04-09 16:29:50,193 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-39:ctx-5870584c) (logid:301a4ad6) Seq 2-5707749577738682460: Response Received:
   2020-04-09 16:29:50,193 DEBUG [c.c.a.t.Request] (DirectAgent-39:ctx-5870584c) (logid:301a4ad6) Seq 2-5707749577738682460: Processing:  { Ans: , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"ec235cfb-3e6e-40aa-9515-e6943b8e2241","id":0,"quiescevm":false,"physicalSize":0}},"result":true,"wait":0}}] }
   2020-04-09 16:29:50,193 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682460: Received:  { Ans: , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 10, { CreateObjectAnswer } }
   2020-04-09 16:29:50,254 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) copyAsync inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT
   2020-04-09 16:29:50,323 ERROR [o.a.c.s.e.DefaultEndPointSelector] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) IR24 select BACKUPSNAPSHOT from primary to secondary 85 dest=85
   2020-04-09 16:29:50,326 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CopyCommand
   2020-04-09 16:29:50,326 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) We are returning the default host to execute commands because the source and destination
   objects are not NFS type.
   2020-04-09 16:29:50,327 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682461: Sending  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"ec235cfb-3e6e-40aa-9515-e6943b8e2241","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/54","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"NFS://10.2.0.16/acs/secondary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-sec1","_role":"Image"}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["snapshots/2/54/14c13d66-53f4-4003-a284-cf266fe1ee3c.vhd","snapshots/2/54/151ca037-2b00-44a3-abb2-b212962b51be.vhd","snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd"],"physicalSize":0}},"executeInSequence":true,"options":{"fullSnapshot":"true"},"options2":{},"wait":21600}}] }
   2020-04-09 16:29:50,328 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682461: Executing:  { Cmd , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"ec235cfb-3e6e-40aa-9515-e6943b8e2241","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"ffda9432-b5c2-41db-ac36-2321b8ed92b3","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["ffda9432-b5c2-41db-ac36-2321b8ed92b3"],"physicalSize":0}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/54","volume":{"uuid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"39bf30d6-f959-359d-b974-b8ebd2d8727f","id":5,"poolType":"NetworkFilesystem","host":"10.2.0.16","path":"/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1","port":2049,"url":"NetworkFilesystem://10.2.0.16/acs/primary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-xs-pri1/?ROLE=Primary&STOREUUID=39bf30d6-f959-359d-b974-b8ebd2d8727f","isManaged":false}},"name":"xen-data-1","size":1073741824,"path":"dd772879-f006-41ec-b09e-db5699f7a7fb","volumeId":54,"vmName":"i-2-22-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":54,"deviceId":1,"hypervisorType":"XenServer"},"parentSnapshotPath":"snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"NFS://10.2.0.16/acs/secondary/ref-trl-774-k-M7-apanic/ref-trl-774-k-M7-apanic-sec1","_role":"Image"}},"vmName":"i-2-22-VM","name":"snap4","hypervisorType":"XenServer","id":85,"quiescevm":false,"parents":["snapshots/2/54/14c13d66-53f4-4003-a284-cf266fe1ee3c.vhd","snapshots/2/54/151ca037-2b00-44a3-abb2-b212962b51be.vhd","snapshots/2/54/a585fa13-201e-40ef-b586-11822133287e.vhd"],"physicalSize":0}},"executeInSequence":true,"options":{"fullSnapshot":"true"},"options2":{},"wait":21600}}] }
   2020-04-09 16:29:52,641 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) No file SR found for path: /var/cloud_mount/569d499d-d7f7-31d4-b124-baf0ad97e161/snapshots/2/54
   2020-04-09 16:29:52,641 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Creating file SR for path [/var/cloud_mount/569d499d-d7f7-31d4-b124-baf0ad97e161/snapshots/2/54] on host [fb4b5939-8702-46b7-bb02-7f43ab6bb9b8]
   2020-04-09 16:30:04,285 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:3d230637-af2f-e354-2db8-e0fccbe62d2b: Removing SR
   2020-04-09 16:30:04,325 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:d3f62ef8-cbbf-3d41-f4bd-c8fb4252adaa: Unplugging pbd
   2020-04-09 16:30:04,651 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Host 10.2.3.240 OpaqueRef:3d230637-af2f-e354-2db8-e0fccbe62d2b: Forgetting
   **2020-04-09 16:30:04,667 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Successfully destroyed snapshot on volume: dd772879-f006-41ec-b09e-db5699f7a7fb execept this current snapshot ec235cfb-3e6e-40aa-9515-e6943b8e2241
   2020-04-09 16:30:04,667 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) New snapshot details: SnapshotTO[datastore=null|volume=null|pathsnapshots/2/54/d4e824b5-f9ac-469f-b94f-dbdf39e8b682.vhd]**
   2020-04-09 16:30:04,667 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) New snapshot physical utilization: 67244544
   2020-04-09 16:30:04,668 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Seq 2-5707749577738682461: Response Received:
   2020-04-09 16:30:04,668 DEBUG [c.c.a.t.Request] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Seq 2-5707749577738682461: Processing:  { Ans: , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/54/d4e824b5-f9ac-469f-b94f-dbdf39e8b682.vhd","id":0,"quiescevm":false,"physicalSize":67244544}},"result":true,"wait":0}}] }
   2020-04-09 16:30:04,668 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-78:ctx-24a25b86) (logid:301a4ad6) Seq 2-5707749577738682461: No more commands found
   2020-04-09 16:30:04,668 DEBUG [c.c.a.t.Request] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Seq 2-5707749577738682461: Received:  { Ans: , MgmtId: 32988805007466, via: 2(ref-trl-774-k-M7-apanic-xs1), Ver: v1, Flags: 110, { CopyCmdAnswer } }
   2020-04-09 16:30:04,690 DEBUG [c.c.r.ResourceLimitManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Updating resource Type = secondary_storage count for Account = 2 Operation = decreasing Amount = 1006497280
   2020-04-09 16:30:04,694 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Done executing VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":54,"policyId":0,"snapshotId":85,"quiesceVm":false,"asyncBackup":false,"userId":2,"accountId":2,"vmId":22,"handlerName":"VolumeApiServiceImpl"}
   2020-04-09 16:30:04,694 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Complete async job-593, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAAVQ
   2020-04-09 16:30:04,695 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Publish async job-593 complete on message bus
   2020-04-09 16:30:04,695 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Wake up jobs related to job-593
   2020-04-09 16:30:04,695 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Update db status for job-593
   2020-04-09 16:30:04,696 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593 ctx-34f207e8) (logid:301a4ad6) Wake up jobs joined with job-593 and disjoin all subjobs created from job- 593
   2020-04-09 16:30:04,702 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Done with run of VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 22, job origin: 592
   2020-04-09 16:30:04,702 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Done executing com.cloud.vm.VmWorkTakeVolumeSnapshot for job-593
   2020-04-09 16:30:04,705 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-8:ctx-b9c690a2 job-592/job-593) (logid:301a4ad6) Remove job-593 from job monitoring
   2020-04-09 16:30:04,720 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Complete async job-592, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SnapshotResponse/snapshot/{"id":"ba2df407-1772-4668-9327-026af717dbce","account":"admin","domainid":"887f0da6-72a9-11ea-9abc-1e00ce01086a","domain":"ROOT","snapshottype":"MANUAL","volumeid":"05c88236-1aa6-44c3-9bf9-bad4edfc34e5","volumename":"xen-data-1","volumetype":"DATADISK","created":"2020-04-09T16:29:45+0000","name":"snap4","intervaltype":"MANUAL","state":"BackedUp","physicalsize":67244544,"zoneid":"e5d78fcd-deb6-4316-9190-136bc788b265","revertable":false,"virtualsize":1073741824,"tags":[]}
   2020-04-09 16:30:04,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Publish async job-592 complete on message bus
   2020-04-09 16:30:04,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Wake up jobs related to job-592
   2020-04-09 16:30:04,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Update db status for job-592
   2020-04-09 16:30:04,721 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592 ctx-eabcd3e5) (logid:301a4ad6) Wake up jobs joined with job-592 and disjoin all subjobs created from job- 592
   2020-04-09 16:30:04,725 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-12:ctx-56cd28cc job-592) (logid:301a4ad6) Done executing org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-592
   2020-04-09 16:30:04,725 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-12:ctx-56cd28cc job-592) (logid:301a4ad6) Remove job-592 from job monitoring

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services