Project

Profile

Help

Issue #1116

Scheduled sync raises TypeError

Added by bmbouter about 6 years ago. Updated over 2 years ago.

Status:
CLOSED - CURRENTRELEASE
Priority:
High
Category:
-
Sprint/Milestone:
-
Start date:
Due date:
Estimated time:
Severity:
3. High
Version:
Master
Platform Release:
2.8.0
OS:
Triaged:
Yes
Groomed:
No
Sprint Candidate:
No
Tags:
Pulp 2
Sprint:
Quarter:

Description

When a scheduled sync runs, a TypeError is raised.

0. start with a fresh/working dev checkout on master with at least the rpm plugin enabled.

1. create a repo

pulp-admin -u admin -p admin rpm repo create --repo-id zoo --relative-url zoo --feed http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo

2. create a scheduled sync to run every minute:

pulp-admin -u admin -p admin rpm repo sync schedules create --repo-id zoo --schedule 2015-06-06T14:29:00Z/PT1M

3. Observe the traceback:

Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128) Task pulp.server.managers.repo.sync.sync[567a6ce3-693c-4f9d-9136-9da1e5e3f234] raised unexpected: TypeError("sync() got an unexpected keyword argument 'overrides'",)

Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128) Traceback (most recent call last):
Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128)   File "/usr/lib/python2.7/site-packages/celery-3.1.11-py2.7.egg/celery/app/trace.py", line 240, in trace_task
Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128)     R = retval = fun(*args, **kwargs)
Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128)   File "/home/bmbouter/Documents/pulp/server/pulp/server/async/tasks.py", line 393, in __call__
Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128)     return super(Task, self).__call__(*args, **kwargs)
Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128)   File "/usr/lib/python2.7/site-packages/celery-3.1.11-py2.7.egg/celery/app/trace.py", line 437, in __protected_call__
Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128)     return self.run(*args, **kwargs)
Jul 06 14:46:31 dhcp129-138.rdu.redhat.com pulp[32689]: celery.worker.job:ERROR: (32689-40128) TypeError: sync() got an unexpected keyword argument 'overrides'

Note that manually performing the sync works. I can do that with:

pulp-admin -u admin -p admin rpm repo create --repo-id zoo --relative-url zoo --feed http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/

When I do that I get:

Successfully created repository [zoo]

[bmbouter@dhcp129-138 pulp]$ pulp-admin -u admin -p admin rpm repo sync run --repo-id zoo
+----------------------------------------------------------------------+
                     Synchronizing Repository [zoo]
+----------------------------------------------------------------------+

This command may be exited via ctrl+c without affecting the request.

Downloading metadata...
[|]
... completed

Downloading repository content...
[==================================================] 100%
RPMs:       32/32 items
Delta RPMs: 0/0 items

... completed

Downloading distribution files...
[==================================================] 100%
Distributions: 0/0 items
... completed

Importing errata...
[-]
... completed

Importing package groups/categories...
[-]
... completed

Task Succeeded

Initializing repo metadata   
[-]
... completed

Publishing Distribution files
[-]
... completed

Publishing RPMs
[==================================================] 100%
32 of 32 items
... completed

Publishing Delta RPMs
... skipped

Publishing Errata
[==================================================] 100%
4 of 4 items
... completed

Publishing Comps file
[==================================================] 100%
3 of 3 items
... completed

Publishing Metadata.
[-]
... completed

Closing repo metadata
[-]
... completed

Generating sqlite files
... skipped

Publishing files to web
[-]
... completed

Writing Listings File
[-]
... completed

Task Succeeded

I thought perhaps the merging of PR 1940 introduced the issue, but when I checkout its parent commit 9e7485126ee0f1688b09086ad27bcd88b0c7677f the issue is also present. Using git-bisect would be a good tool to find the commit that introduced the regression.

Associated revisions

Revision 01367855 View on GitHub
Added by Austin Macdonald about 6 years ago

scheduled tasks queue sync and publish instead of call

fixes #1116

Revision 01367855 View on GitHub
Added by Austin Macdonald about 6 years ago

scheduled tasks queue sync and publish instead of call

fixes #1116

History

#1 Updated by bmbouter about 6 years ago

  • Description updated (diff)

#2 Updated by amacdona@redhat.com about 6 years ago

  • Status changed from NEW to ASSIGNED
  • Assignee set to amacdona@redhat.com

#3 Updated by amacdona@redhat.com about 6 years ago

  • Status changed from ASSIGNED to POST
  • Platform Release set to 2.7.0

#4 Updated by amacdona@redhat.com about 6 years ago

  • Platform Release changed from 2.7.0 to master

#5 Updated by Anonymous about 6 years ago

  • Status changed from POST to MODIFIED
  • % Done changed from 0 to 100

#6 Updated by mhrivnak about 6 years ago

  • Triaged changed from No to Yes

#7 Updated by mhrivnak almost 6 years ago

  • Platform Release changed from master to 2.8.0

#8 Updated by dkliban@redhat.com over 5 years ago

  • Status changed from MODIFIED to 5

#9 Updated by pthomas@redhat.com over 5 years ago

  • Status changed from 5 to 6

[root@mgmt3 ~]# rpm -qa pulp-server
pulp-server-2.8.0-0.6.beta.git.40.28675fb.el7.noarch
[root@mgmt3 ~]#

[root@mgmt3 ~]# pulp-admin -u admin -p admin rpm repo create --repo-id zoo --relative-url zoo --feed http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo
Successfully created repository [zoo]

[root@mgmt3 ~]# pulp-admin -u admin -p admin rpm repo sync schedules create --repo-id zoo --schedule 2015-06-06T14:29:00Z/PT1M
Schedule successfully created

[root@mgmt3 ~]#

Mar 02 10:40:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading metadata from http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/.
Mar 02 10:40:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 10:40:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 10:40:01 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: Parsing metadata.
Mar 02 10:40:01 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading metadata from http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/.
Mar 02 10:40:01 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 10:40:01 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 10:40:02 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: Parsing metadata.
Mar 02 10:40:02 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading metadata from http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/.
Mar 02 10:40:02 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 10:40:02 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 10:40:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: Parsing metadata.
Mar 02 10:40:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: upstream repo metadata has not changed. Skipping steps.
Mar 02 10:40:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading additional units.
Mar 02 10:40:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 10:40:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 10:40:04 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 10:40:04 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp_rpm.plugins.importers.yum.sync:INFO: Sync complete.
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4059]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[7871378c-6c7d-435e-b4d0-e5c37b9276ca]
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp.server.async.tasks:INFO: resetting consecutive failure count for schedule 56d708b1c6b14a1422c4c1b5
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[3888]: celery.worker.job:INFO: Task pulp.server.managers.repo.sync.sync[86e81b82-ea9c-4e59-b88e-294c6eaf3b44] succeeded in 5.18908388191s: <pulp.server.async.tasks.TaskResult object at 0x3e6d890>
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[3888]: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[b5dbcace-de42-453d-bc6f-aec9f00513fd] succeeded in 0.0137648540549s: None
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[3888]: celery.worker.strategy:INFO: Received task: pulp.server.managers.repo.publish.publish[99735098-1254-49c4-8d8e-ee10b9ce01fa]
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4059]: celery.worker.job:INFO: Task pulp.server.async.tasks._queue_reserved_task[7871378c-6c7d-435e-b4d0-e5c37b9276ca] succeeded in 0.0383462859318s: None
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[3888]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._release_resource[f8fff04e-01d5-40fc-b2ba-0e809d14822f]
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp.plugins.pulp_rpm.plugins.distributors.yum.metadata.metadata:WARNING: Overwriting existing metadata file [/var/cache/pulp/reserved_resource_worker-2@mgmt3.rhq.lab.eng.bos.redhat.com/99735098-1254-49c4-8d8e-ee10b9ce01fa/repodata/repomd.xml]
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[4097]: pulp.server.async.tasks:INFO: resetting consecutive failure count for schedule 56d708b1c6b14a1422c4c1b5
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[3888]: celery.worker.job:INFO: Task pulp.server.managers.repo.publish.publish[99735098-1254-49c4-8d8e-ee10b9ce01fa] succeeded in 0.388077029027s: {'exception': None, 'repo_id': u'zoo', 'traceback': None, 'started': '2016-03-02T15:40:05Z', '_ns': u'repo_publish_results',...
Mar 02 10:40:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[3888]: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[f8fff04e-01d5-40fc-b2ba-0e809d14822f] succeeded in 0.00963698991109s: None

#10 Updated by dkliban@redhat.com over 5 years ago

  • Status changed from 6 to CLOSED - CURRENTRELEASE

#12 Updated by bmbouter over 2 years ago

  • Tags Pulp 2 added

Please register to edit this issue

Also available in: Atom PDF