Bug 680444 - exception during status api call
Summary: exception during status api call
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Pulp
Classification: Retired
Component: z_other
Version: unspecified
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
: Sprint 21
Assignee: John Matthews
QA Contact: Preethi Thomas
URL:
Whiteboard:
Depends On:
Blocks: verified-to-close
TreeView+ depends on / blocked
 
Reported: 2011-02-25 15:09 UTC by Shannon Hughes
Modified: 2011-08-16 12:21 UTC (History)
1 user (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-08-16 12:07:48 UTC
Embargoed:


Attachments (Terms of Use)

Description Shannon Hughes 2011-02-25 15:09:02 UTC
Description of problem:
When syncing three repos and then checking their status with the sync id i am seeing an exception from pulp being thrown. stack trace below:

#
Parameters: {"repo_id"=>"41111ZZ-1234999", "sync_id"=>"ea48c073-40ef-11e0-9ecf-00219b3b5088", "_"=>"1298646013964"}
#
Resource GET request: /pulp/api/repositories/41111ZZ-1234999/sync/ea48c073-40ef-11e0-9ecf-00219b3b5088/
#
{
#
  "result": null,
#
  "method_name": "_sync",
#
  "status_path": "/pulp/api/repositories/41111ZZ-1234999/sync/ea48c073-40ef-11e0-9ecf-00219b3b5088/",
#
  "scheduled_time": 0,
#
  "progress": {
#
    "step": "Downloading Metadata",
#
    "num_success": 0,
#
    "error_details": [
#
 
#
    ],
#
    "details": {
#
    },
#
    "num_download": 0,
#
    "item_name": null,
#
    "num_error": 0,
#
    "size_left": 0,
#
    "items_total": 0,
#
    "status": null,
#
    "items_left": 0,
#
    "size_total": 0
#
  },
#
  "id": "ea48c073-40ef-11e0-9ecf-00219b3b5088",
#
  "traceback": [
#
    "Traceback (most recent call last):\n",
#
    "  File \"/git/pulp/src/pulp/server/tasking/task.py\", line 131, in run\n    result = self.callable(*self.args, **self.kwargs)\n",
#
    "  File \"/git/pulp/src/pulp/server/api/repo.py\", line 1308, in _sync\n    synchronizer)\n",
#
    "  File \"/git/pulp/src/pulp/server/api/repo_sync.py\", line 103, in sync\n    repo_dir = synchronizer.sync(repo, repo_source, skip_dict, progress_callback)\n",
#
    "  File \"/git/pulp/src/pulp/server/api/repo_sync.py\", line 434, in sync\n    report = self.yum_repo_grinder.fetchYumRepo(store_path, callback=progress_callback)\n",
#
    "  File \"/usr/lib/python2.7/site-packages/grinder/RepoFetch.py\", line 311, in fetchYumRepo\n    self.yumFetch.getRepoData()\n",
#
    "  File \"/usr/lib/python2.7/site-packages/grinder/RepoFetch.py\", line 119, in getRepoData\n    for ftype in self.repo.repoXML.fileTypes():\n",
#
    "  File \"/usr/lib/python2.7/site-packages/yum/yumRepo.py\", line 1413, in <lambda>\n    repoXML = property(fget=lambda self: self._getRepoXML(),\n",
#
    "  File \"/usr/lib/python2.7/site-packages/yum/yumRepo.py\", line 1405, in _getRepoXML\n    self._loadRepoXML(text=self)\n",
#
    "  File \"/usr/lib/python2.7/site-packages/yum/yumRepo.py\", line 1395, in _loadRepoXML\n    return self._groupLoadRepoXML(text, self._mdpolicy2mdtypes())\n",
#
    "  File \"/usr/lib/python2.7/site-packages/yum/yumRepo.py\", line 1370, in _groupLoadRepoXML\n    if self._commonLoadRepoXML(text):\n",
#
    "  File \"/usr/lib/python2.7/site-packages/yum/yumRepo.py\", line 1198, in _commonLoadRepoXML\n    result = self._getFileRepoXML(local, text)\n",
#
    "  File \"/usr/lib/python2.7/site-packages/yum/yumRepo.py\", line 985, in _getFileRepoXML\n    size=102400) # setting max size as 100K\n",
#
    "  File \"/usr/lib/python2.7/site-packages/yum/yumRepo.py\", line 808, in _getFile\n    size=size\n",
#
    "  File \"/usr/lib/python2.7/site-packages/urlgrabber/mirror.py\", line 408, in urlgrab\n    return self._mirror_try(func, url, kw)\n",
#
    "  File \"/usr/lib/python2.7/site-packages/urlgrabber/mirror.py\", line 394, in _mirror_try\n    return func_ref( *(fullurl,), **kwargs )\n",
#
    "  File \"/usr/lib/python2.7/site-packages/urlgrabber/grabber.py\", line 982, in urlgrab\n    return self._retry(opts, retryfunc, url, filename)\n",
#
    "  File \"/usr/lib/python2.7/site-packages/urlgrabber/grabber.py\", line 886, in _retry\n    r = apply(func, (opts,) + args, {})\n",
#
    "  File \"/usr/lib/python2.7/site-packages/urlgrabber/grabber.py\", line 968, in retryfunc\n    fo = PyCurlFileObject(url, filename, opts)\n",
#
    "  File \"/usr/lib/python2.7/site-packages/urlgrabber/grabber.py\", line 1063, in __init__\n    self._do_open()\n",
#
    "  File \"/usr/lib/python2.7/site-packages/urlgrabber/grabber.py\", line 1350, in _do_open\n    self._set_opts()\n",
#
    "  File \"/usr/lib/python2.7/site-packages/urlgrabber/grabber.py\", line 1161, in _set_opts\n    self.curl_obj.setopt(pycurl.NOPROGRESS, False)\n",
#
    "error: cannot invoke setopt() - perform() is currently running\n"
#
  ],
#
  "exception": "error('cannot invoke setopt() - perform() is currently running',)",
#
  "finish_time": {
#
    "$date": 1298627999362
#
  },
#
  "state": "error",
#
  "start_time": {
#
    "$date": 1298627999313
#
  }
#
}
#
Completed   in 79ms 

Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1.
2.
3.
  
Actual results:


Expected results:


Additional info:

Comment 1 Shannon Hughes 2011-02-25 15:11:26 UTC
suggestion...if a thread is already working on a sync id and another request comes in, then return the existing status.

Comment 2 Jason Connor 2011-02-25 16:03:45 UTC
The sync status call is correctly reporting a traceback from grinder

Comment 3 John Matthews 2011-03-09 14:29:49 UTC
Issue is that grinder is using yum for fetching repo metadata, this process needs to be serial.  Looks like yum is using a global pycurl object, so subsequent calls to fetch while another fetch is in progress throws an error.

Note: The actual download of content (rpms, drpms, files, etc) is done by grinder/pycurl and is fine executing in parallel.

The issue here is fetching of metadata which happens in the beginning of a sync.

I am under the impression that a newer version of yum will fix this issue, for near term fix the proposed change for grinder is to catch this exception, wait a few random seconds and re-try.  


QE:  To simulate this scenario, run 3 long syncs all starting at the same time (key is metadata needs to be fairly large, a few MB).  I would recommend syncing fedora 12, 13, 14 all starting same time to see this problem.  When it's fixed, you should see that one of the syncs starts right away while others staying in "waiting/fetching metadata", within a few minutes all syncs should have completed metadata fetching, then all 3 syncs will be downloading packages in parallel.

Comment 4 John Matthews 2011-03-10 00:02:42 UTC
Fixed in grinder 0.86

http://git.fedorahosted.org/git/?p=grinder.git;a=commitdiff;h=d95ec3eebbb29f6c300e0c9efab964cd9f18f9e0


QE: Perform 3 syncs at the same time from inside pulp.
Note this needs to be tested from inside pulp and not from grinder, we need all 3 syncs to be running in the same process.
Also note this problem isn't seen on Fedora 12, needs to be Fedora 14 where yum is using pycurl.

Comment 5 Jeff Ortel 2011-03-12 00:17:29 UTC
Build: 0.151

Comment 6 Jeff Ortel 2011-03-12 00:18:03 UTC
Build: 0.151

Comment 7 Preethi Thomas 2011-04-28 21:05:17 UTC
verified
[root@preethi ~]# rpm -q pulp
pulp-0.0.172-1.fc14.noarch


[root@preethi ~]# curl -k -u admin:admin https://localhost/pulp/api/repositories/f14-original/sync/8fa5d8ae-71db-11e0-9622-002564a85a58/
{"scheduled_time": {"$date": 1304010464290}, "exception": null, "status_path": "/pulp/api/repositories/f14-original/sync/8fa5d8ae-71db-11e0-9622-002564a85a58/", "finish_time": null, "start_time": "1304024864", "traceback": null, "method_name": "_sync", "state": "running", "result": null, "progress": {"status": "FINISHED", "num_success": 2773, "size_total": 3273644559, "num_download": 63, "item_name": null, "items_left": 0, "items_total": 2773, "step": "Running Createrepo", "size_left": 0, "details": {"tree_file": {"num_success": 7, "total_count": 7, "items_left": 0, "size_left": 0, "total_size_bytes": 0, "num_error": 0}, "rpm": {"num_success": 2766, "total_count": 2766, "items_left": 0, "size_left": 0, "total_size_bytes": 3273644559, "num_error": 0}}, "error_details": [], "num_error": 0}, "id": "8fa5d8ae-71db-11e0-9622-002564a85a58"}[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# curl -k -u admin:admin https://localhost/pulp/api/repositories/f14-original/sync/d23f7e17-71db-11e0-8a9a-002564a85a58/
{"scheduled_time": {"$date": 1304010576026}, "exception": null, "status_path": "/pulp/api/repositories/f14-original/sync/d23f7e17-71db-11e0-8a9a-002564a85a58/", "finish_time": null, "start_time": "1304024976", "traceback": null, "method_name": "_sync", "state": "running", "result": null, "progress": {"status": "downloaded", "num_success": 2891, "size_total": 3350601976, "num_download": 0, "item_name": "gamin-python-0.1.10-9.fc15.x86_64.rpm", "items_left": 52, "items_total": 2943, "step": "Downloading Items or Verifying", "size_left": 246458564, "details": {"tree_file": {"num_success": 0, "total_count": 6, "items_left": 6, "size_left": 0, "total_size_bytes": 0, "num_error": 0}, "rpm": {"num_success": 2891, "total_count": 2937, "items_left": 46, "size_left": 246458564, "total_size_bytes": 3350601976, "num_error": 0}}, "error_details": [], "num_error": 0}, "id": "d23f7e17-71db-11e0-8a9a-002564a85a58"}[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# curl -k -u admin:admin https://localhost/pulp/api/repositories/f14-original/sync/bea84600-71db-11e0-8a37-002564a85a58/
{"scheduled_time": {"$date": 1304010543159}, "exception": null, "status_path": "/pulp/api/repositories/f14-original/sync/bea84600-71db-11e0-8a37-002564a85a58/", "finish_time": null, "start_time": "1304024943", "traceback": null, "method_name": "_sync", "state": "running", "result": null, "progress": {"status": "FINISHED", "num_success": 3111, "size_total": 3393564951, "num_download": 1, "item_name": null, "items_left": 0, "items_total": 3111, "step": "Running Createrepo", "size_left": 0, "details": {"tree_file": {"num_success": 9, "total_count": 9, "items_left": 0, "size_left": 0, "total_size_bytes": 0, "num_error": 0}, "rpm": {"num_success": 3102, "total_count": 3102, "items_left": 0, "size_left": 0, "total_size_bytes": 3393564951, "num_error": 0}}, "error_details": [], "num_error": 0}, "id": "bea84600-71db-11e0-8a37-002564a85a58"}[root@preethi ~]# 
[root@preethi ~]#

Comment 8 Preethi Thomas 2011-04-28 21:07:36 UTC
[root@preethi ~]# curl -k -u admin:admin https://localhost/pulp/api/repositories/f13-original/sync/bea84600-71db-11e0-8a37-002564a85a58/
{"scheduled_time": {"$date": 1304010543159}, "exception": null, "status_path": "/pulp/api/repositories/f13-original/sync/bea84600-71db-11e0-8a37-002564a85a58/", "finish_time": null, "start_time": "1304024943", "traceback": null, "method_name": "_sync", "state": "running", "result": null, "progress": {"status": "FINISHED", "num_success": 3111, "size_total": 3393564951, "num_download": 1, "item_name": null, "items_left": 0, "items_total": 3111, "step": "Running Createrepo", "size_left": 0, "details": {"tree_file": {"num_success": 9, "total_count": 9, "items_left": 0, "size_left": 0, "total_size_bytes": 0, "num_error": 0}, "rpm": {"num_success": 3102, "total_count": 3102, "items_left": 0, "size_left": 0, "total_size_bytes": 3393564951, "num_error": 0}}, "error_details": [], "num_error": 0}, "id": "bea84600-71db-11e0-8a37-002564a85a58"}[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# curl -k -u admin:admin https://localhost/pulp/api/repositories/f15-beta/sync/d23f7e17-71db-11e0-8a9a-002564a85a58/
{"scheduled_time": {"$date": 1304010576026}, "exception": null, "status_path": "/pulp/api/repositories/f15-beta/sync/d23f7e17-71db-11e0-8a9a-002564a85a58/", "finish_time": null, "start_time": "1304024976", "traceback": null, "method_name": "_sync", "state": "running", "result": null, "progress": {"status": "FINISHED", "num_success": 2943, "size_total": 3350601976, "num_download": 549, "item_name": null, "items_left": 0, "items_total": 2943, "step": "Running Createrepo", "size_left": 0, "details": {"tree_file": {"num_success": 6, "total_count": 6, "items_left": 0, "size_left": 0, "total_size_bytes": 0, "num_error": 0}, "rpm": {"num_success": 2937, "total_count": 2937, "items_left": 0, "size_left": 0, "total_size_bytes": 3350601976, "num_error": 0}}, "error_details": [], "num_error": 0}, "id": "d23f7e17-71db-11e0-8a9a-002564a85a58"}[root@preethi ~]#

Comment 9 Preethi Thomas 2011-08-16 12:07:48 UTC
Closing with Community Release 15

pulp-0.0.223-4.

Comment 10 Preethi Thomas 2011-08-16 12:21:13 UTC
Closing with Community Release 15

pulp-0.0.223-4.


Note You need to log in before you can comment on or make changes to this bug.