Bug 760601

Summary: repo clone cannot be cancelled after package sync stage
Product: [Retired] Pulp Reporter: Preethi Thomas <pthomas>
Component: user-experienceAssignee: Sayli Karmarkar <skarmark>
Status: CLOSED CURRENTRELEASE QA Contact: Preethi Thomas <pthomas>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 1.0.0CC: cperry, skarmark
Target Milestone: ---Keywords: Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-02-24 20:11:59 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Preethi Thomas 2011-12-06 15:38:33 UTC
Description of problem:
cancel_clone result is different depending on when the command was issued

if cancel clone is issued while the package sync is happening the the status shows as clone cancelled.
[root@preethi ~]# pulp-admin repo clone --id=f15 --clone_id=f15-clone --feed=origin -F
Repository [f15] is being cloned as [f15-clone]
Clone: Canceled
Item Details: 
Tree Files: 0/5
RPMs: 22/2935

but if cancel_clone is issued after the package sync stage, Clone goes to finished.


[root@preethi ~]# pulp-admin repo clone --id=f15 --clone_id=f15-clone --feed=origin -F
Repository [f15] is being cloned as [f15-clone]
Clone: Finished
Item Details: 
Tree Files: 5/5
RPMs: 2935/2935


From pulp.log

2011-12-06 10:49:10,763 27560:139821206427392: pulp.server.api.repo_clone_task:INFO: repo_clone_task:55 RepoCloneTask repo <f15-clone> has been canceled
2011-12-06 10:49:10,766 27560:139821206427392: pulp.server.api.repo:INFO: repo:522 Delete API call invoked f15-clone
2011-12-06 10:49:10,769 27560:139821206427392: pulp.server.api.keystore:INFO: keystore:200 mkdir: /var/lib/pulp/published/gpg/f15-clone
2011-12-06 10:49:10,770 27560:139821206427392: pulp.server.api.keystore:INFO: keystore:185 unlinking: /var/lib/pulp/published/gpg/f15-clone
2011-12-06 10:49:10,998 27560:139821206427392: pulp.server.api.repo:INFO: repo:628 removing repo files .... /var/lib/pulp//repos/f15-clone
2011-12-06 10:49:19,756 27560:139820705769216: pulp.server.api.synchronizers:INFO: synchronizers:405 No image files to import to repo..
2011-12-06 10:49:19,759 27560:139820705769216: pulp.server.api.synchronizers:INFO: synchronizers:385 No metadata for 'File Sync' present; no files to import to repo..
2011-12-06 10:49:19,763 27560:139820705769216: pulp.server.api.repo_sync:INFO: repo_sync:275 Sync returned 2935 packages, 0 errata in 22.340293169 seconds
2011-12-06 10:49:19,767 27560:139820705769216: pulp.server.api.repo_sync:INFO: repo_sync:286 0 old packages to process, 2935 new packages to process
2011-12-06 10:49:20,199 27560:139820705769216: pulp.server.api.repo_sync:INFO: repo_sync:301 Examining 0 errata from repo f15-clone
2011-12-06 10:49:20,209 27560:139820705769216: pulp.server.api.repo_sync:INFO: repo_sync:305 Removing 0 old errata from repo f15-clone
2011-12-06 10:49:20,261 27560:139820705769216: pulp.server.api.repo_sync:INFO: repo_sync:314 Adding 0 new errata to repo f15-clone
2011-12-06 10:49:21,248 27560:139820705769216: pulp.server.api.keystore:INFO: keystore:200 mkdir: /var/lib/pulp//repos/f15-clone
2011-12-06 10:49:21,249 27560:139820705769216: pulp.server.api.keystore:INFO: keystore:200 mkdir: /var/lib/pulp/published/gpg/f15-clone
2011-12-06 10:49:21,249 27560:139820705769216: pulp.server.api.repo:INFO: repo:1660 repository (f15-clone), added keys: []
2011-12-06 10:49:21,290 27560:139820705769216: pulp.server.api.repo:INFO: repo:1902 Successfully added files [u'ef9dcc30-c873-422f-8624-fea5fa98c353'] to repo f15-clone
2011-12-06 10:49:21,297 27560:139820705769216: pulp.server.tasking.task:INFO: task:440 Task succeeded: Task cdc619e1-2021-11e1-bcbe-002564a85a58: _clone(f15-clone, feed=origin, progress_callback=<bound method RepoCloneTask.progress_callback of <pulp.server.api.repo_clone_task.RepoCloneTask object at 0x7f2a82e3d250>>, clone_name=f15-clone, relative_path=None, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f2a8ccdb610>, filters=[], id=f15, groupid=None)
2011-12-06 10:50:01,012 27560:139820705769216: pulp.server.api.repo_sync:INFO: repo_sync:254 Sync invoked for repo <fedora15>
2011-12-06 10:50:01,588 27560:139820705769216: pulp.server.api.repo_sync:INFO: repo_sync:268 Sync of fedora15 starting, skip_dict = {'distribution': 1}
2011-12-06 10:50:02,313 27560:139820705769216: pulp.server.api.synchronizers:INFO: synchronizers:680 cacert = <None>, cert = <None>
2011-12-06 10:50:02,314 27560:139820705769216: pulp.server.api.synchronizers:INFO: synchronizers:728 Fetching repo to </var/lib/pulp//repos/fedora15> with verify_options <{'checksum': True, 'size': True}>
2011-12-06 10:50:17,611 27560:139820705769216: pulp.server.api.synchronizers:INFO: synchronizers:736 YumSynchronizer reported 2935 successes, 0 downloads, 0 errors





Version-Release number of selected component (if applicable):
[root@preethi ~]# rpm -q pulp
pulp-0.0.254-1.fc15.noarch
[root@preethi ~]#

Comment 1 Pradeep Kilambi 2011-12-19 18:58:02 UTC
commit fb94ec10333b37331e50180003080759eff41587

After fix the sync will record the cancel and ends the clone in canceled state

Repository [testel6] is being cloned as [testel6_cln]
Clone: Canceled
Item Details: 
Tree Files: 5/5
RPMs: 5608/5609

Comment 2 Jeff Ortel 2012-01-04 21:48:43 UTC
build: 0.256

Comment 3 Preethi Thomas 2012-01-05 18:48:05 UTC
Looks like there are still stages at which the clone status says Finished, but if you list the repo you can see that there is no repo that was cloned.

[root@preethi CDN]# rpm -q pulp
pulp-0.0.256-1.fc15.noarch


[root@preethi CDN]# pulp-admin repo clone --id=f15 --clone_id=f15-clone --feed=origin -F
Repository [f15] is being cloned as [f15-clone]
Clone: Finished
Item Details: 
Tree Files: 5/5
RPMs: 2935/2935

[root@preethi CDN]# pulp-admin repo info --id=f15-cloneerror:  error: operation failed: No repository f15-clone
[root@preethi CDN]#

Comment 4 Pradeep Kilambi 2012-01-09 22:09:21 UTC
assigning to sayli for further investigation on why cancel clone method is not seeting the self.stopped correctly.

Comment 5 Sayli Karmarkar 2012-01-15 07:13:48 UTC
After trying out a few things, I noticed that the problem was happening only in case of repositories with distributions. It seems like we were not catching CancelException when importing distributions. Now cancel clone and sync can be canceled correctly when importing distributions as well.  

commit f5c60eca3f9965eeb81b7af679449d3fb2af58ae
Author: Sayli Karmarkar <skarmark>
Date:   Sat Jan 14 22:56:21 2012 -0800

    760601 - updated code for adding distribution and files to catch CancelException in case of cancel_clone or cancel_sync

Comment 6 Jeff Ortel 2012-01-16 22:47:55 UTC
build: 0.258

Comment 7 Preethi Thomas 2012-01-20 17:11:37 UTC
fails _qa

this still seems to be happening
[root@preethi ~]# pulp-admin -u admin -p admin  repo clone --id=f15 --clone_id=f15-clone2  --feed=origin -F
Repository [f15] is being cloned as [f15-clone2]
Clone: Finished
Item Details: 
Tree Files: 5/5
RPMs: 2935/2935


[root@preethi ~]#  pulp-admin -u admin -p admin  repo cancel_clone --id=f15-clone2
Clone for this repository f15-clone2 is being canceled

from pulp.log

2012-01-20 12:20:33,937 6330:139987009926912: pulp.server.api.repo_sync:INFO: repo_sync:95 Creating [origin] feed repo [f15-clone2] cloned from [f15] with relative_path [f15-clone2]
2012-01-20 12:20:34,662 6330:139987009926912: pulp.server.util:INFO: util:470 started repo metadata update: ['createrepo', '--database', '--checksum', 'sha256', '--update', '/var/lib/pulp//repos/f15-clone2']
2012-01-20 12:20:35,627 6330:139987009926912: pulp.server.util:INFO: util:520 createrepo on /var/lib/pulp//repos/f15-clone2 finished
2012-01-20 12:20:35,627 6330:139987009926912: pulp.server.util:INFO: util:522 Nothing further to check; we got our fresh metadata
2012-01-20 12:20:36,354 6330:139986573702912: pulp.server.api.repo_sync:INFO: repo_sync:254 Sync invoked for repo <f15-clone2>
2012-01-20 12:20:36,355 6330:139986573702912: pulp.server.api.repo_sync:INFO: repo_sync:268 Sync of f15-clone2 starting, skip_dict = {}
2012-01-20 12:20:36,358 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:1153 sync of /var/lib/pulp//repos/released/F-15/GOLD/Fedora/x86_64/os for repo f15-clone2
2012-01-20 12:20:36,420 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:801 Found 2935 packages in /var/lib/pulp//repos/released/F-15/GOLD/Fedora/x86_64/os
2012-01-20 12:20:36,637 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:813 Found 0 delta rpm packages in /var/lib/pulp//repos/released/F-15/GOLD/Fedora/x86_64/os
2012-01-20 12:20:36,697 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:801 Found 2935 packages in /var/lib/pulp//repos/released/F-15/GOLD/Fedora/x86_64/os
2012-01-20 12:20:39,568 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:990 Finished cloning 2935 packages
2012-01-20 12:20:39,734 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:813 Found 0 delta rpm packages in /var/lib/pulp//repos/released/F-15/GOLD/Fedora/x86_64/os
2012-01-20 12:20:39,736 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:1085 creating a symlink for treeinfo file from /var/lib/pulp/distributions/ks-Fedora-Fedora-15-x86_64/.treeinfo to /var/lib/pulp//repos/f15-clone2/.treeinfo
2012-01-20 12:20:39,740 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:1208 Copying repodata from /var/lib/pulp//repos/released/F-15/GOLD/Fedora/x86_64/os/repodata to /var/lib/pulp//repos/f15-clone2/repodata
2012-01-20 12:20:42,575 6330:139986573702912: pulp.server.api.distribution:INFO: distribution:50 Distribution with id ks-Fedora-Fedora-15-x86_64 already exists
2012-01-20 12:20:42,575 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:436 Created a distributionID ks-Fedora-Fedora-15-x86_64
2012-01-20 12:20:42,580 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:387 No metadata for 'File Sync' present; no files to import to repo..
2012-01-20 12:20:42,585 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:356 Loading comps group info from: /var/lib/pulp//repos/f15-clone2/repodata/2837838aa7c648a3b6cd5eb754dee7b1df7b98bc42c58532937d9e4f397db7e8-2837838aa7c648a3b6cd5eb754dee7b1df7b98bc42c58532937d9e4f397db7e8-Fedora-15-comps.xml
2012-01-20 12:20:42,954 6330:139986573702912: pulp.server.api.synchronizers:INFO: synchronizers:377 Skipping errata imports from sync process
2012-01-20 12:20:43,416 6330:139986573702912: pulp.server.api.repo_sync:INFO: repo_sync:275 Sync returned 2935 packages, 0 errata in 7.06084990501 seconds
2012-01-20 12:20:43,854 6330:139986573702912: pulp.server.api.repo_sync:INFO: repo_sync:286 0 old packages to process, 2935 new packages to process
2012-01-20 12:20:45,700 6330:139987374458624: pulp.server.api.repo_clone_task:INFO: repo_clone_task:50 RepoCloneTask cancel invoked repo <f15-clone2>. Will cancel synchronizer <<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f5134434210>>
2012-01-20 12:20:45,710 6330:139987374458624: pulp.server.api.synchronizers:INFO: synchronizers:770 Synchronizer stop has completed
2012-01-20 12:20:45,715 6330:139987374458624: pulp.server.api.repo_clone_task:INFO: repo_clone_task:54 RepoCloneTask repo <f15-clone2> has been canceled
2012-01-20 12:20:45,846 6330:139986573702912: pulp.server.api.repo_sync:INFO: repo_sync:301 Examining 0 errata from repo f15-clone2
2012-01-20 12:20:46,703 6330:139986573702912: pulp.server.api.repo_sync:INFO: repo_sync:305 Removing 0 old errata from repo f15-clone2
2012-01-20 12:20:47,029 6330:139987374458624: pulp.server.api.repo:INFO: repo:529 Delete API call invoked f15-clone2
2012-01-20 12:20:47,237 6330:139987374458624: pulp.server.api.keystore:INFO: keystore:200 mkdir: /var/lib/pulp/published/gpg/f15-clone2
2012-01-20 12:20:47,457 6330:139987374458624: pulp.server.api.keystore:INFO: keystore:185 unlinking: /var/lib/pulp/published/gpg/f15-clone2
2012-01-20 12:20:48,933 6330:139986573702912: pulp.server.api.repo_sync:INFO: repo_sync:314 Adding 0 new errata to repo f15-clone2
2012-01-20 12:20:51,371 6330:139986573702912: pulp.server.api.keystore:INFO: keystore:200 mkdir: /var/lib/pulp/published/gpg/f15-clone2
2012-01-20 12:20:51,373 6330:139986573702912: pulp.server.api.repo:INFO: repo:1744 repository (f15-clone2), added keys: []
2012-01-20 12:20:52,180 6330:139986573702912: pulp.server.api.repo:INFO: repo:1986 Successfully added files [] to repo f15-clone2
2012-01-20 12:20:52,193 6330:139986573702912: pulp.server.tasking.task:INFO: task:440 Task succeeded: Task 10a2d38f-438b-11e1-953c-002564a85a58: _clone(f15-clone2, feed=origin, progress_callback=<bound method RepoCloneTask.progress_callback of <pulp.server.api.repo_clone_task.RepoCloneTask object at 0x7f513c7b5110>>, clone_name=f15-clone2, relative_path=f15-clone2, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f5134434210>, filters=[], id=f15, groupid=None)
2012-01-20 12:20:55,733 6330:139987374458624: pulp.server.api.repo:INFO: repo:1904 Successfully removed distribution ks-Fedora-Fedora-15-x86_64 from repo f15-clone2
2012-01-20 12:20:55,733 6330:139987374458624: pulp.server.api.repo:INFO: repo:1920 Unlinking /var/lib/pulp/published/ks/f15-clone2
2012-01-20 12:20:55,739 6330:139987374458624: pulp.server.api.repo:INFO: repo:602 Distribution Id [ks-Fedora-Fedora-15-x86_64] has other references; leaving it in the db
2012-01-20 12:20:55,895 6330:139987374458624: pulp.server.api.repo:INFO: repo:638 removing repo files .... /var/lib/pulp//repos/f15-clone2

Comment 8 Preethi Thomas 2012-01-20 17:12:32 UTC
[root@preethi ~]# pulp-admin -u admin -p admin  repo info --id=f15-clone2
error:  operation failed: No repository f15-clone2
[root@preethi ~]#

Comment 9 Sayli Karmarkar 2012-01-20 20:21:35 UTC
Fixed. Looks like there was one more missing CancelException during sync when removing packages and errata that no longer exist.

Comment 10 Jeff Ortel 2012-01-21 00:23:00 UTC
build: 0.259

Comment 11 Preethi Thomas 2012-01-25 18:40:45 UTC
verified
[root@preethi ~]# rpm -q pulp
pulp-0.0.261-1.fc15.noarch

[root@preethi ~]# pulp-admin repo clone --id=f15 --clone_id=f15-clone --feed=origin -F
Repository [f15] is being cloned as [f15-clone]
Clone: Canceled
Item Details: 
Tree Files: 5/5
RPMs: 2935/2935

[root@preethi ~]# pulp-admin repo cancel_clone --id=f15-clone
Clone for this repository f15-clone is being canceled

Comment 12 Preethi Thomas 2012-02-24 20:11:59 UTC
Pulp v1.0 is released
Closed Current Release.