Project

Profile

Help

Actions
Send by e-mail Copy link

Issue #1154

closed

scheduled tasks fail to run

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

Status:
CLOSED - CURRENTRELEASE
Priority:
High
Assignee:
dkliban@redhat.com
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:
Easy Fix, Pulp 2
Sprint:
Quarter:

Description

Tasks that are dispatched by the scheduler, such as the document reaper task, fail to run. The scheduler sends them to the workers, but the workers don't know about the task type.

celery.worker.consumer:ERROR: (13806-03680) Received unregistered task of type 'pulp.server.db.reaper.queue_reap_expired_documents'.
celery.worker.consumer:ERROR: (13806-03680) The message has been ignored and discarded.
celery.worker.consumer:ERROR: (13806-03680)
celery.worker.consumer:ERROR: (13806-03680) Did you remember to import the module containing this task?
celery.worker.consumer:ERROR: (13806-03680) Or maybe you are using relative imports?
celery.worker.consumer:ERROR: (13806-03680) Please see http://bit.ly/gLye1c for more information.
celery.worker.consumer:ERROR: (13806-03680)
celery.worker.consumer:ERROR: (13806-03680) The full contents of the message body was:
celery.worker.consumer:ERROR: (13806-03680) {'utc': True, 'chord': None, 'args': [], 'retries': 0, 'expires': None, 'task': 'pulp.server.db.reaper.queue_reap_expired_documents', 'callbacks': None, 'errbacks': None, 'timelimit': (None, None), 'taskset': None, 'kwargs': {}, 'eta': None, 'id': 'c98909e5-5436-444a-a07d-9fc6b1e0ab06'} (246b)
celery.worker.consumer:ERROR: (13806-03680)
celery.worker.consumer:ERROR: (13806-03680) Traceback (most recent call last):
celery.worker.consumer:ERROR: (13806-03680)   File "/usr/lib/python2.7/site-packages/celery/worker/consumer.py", line 455, in on_task_received
celery.worker.consumer:ERROR: (13806-03680)     strategies[name](message, body,
celery.worker.consumer:ERROR: (13806-03680) KeyError: 'pulp.server.db.reaper.queue_reap_expired_documents'
celery.beat:INFO: Scheduler: Sending due task reap_expired_documents (pulp.server.db.reaper.queue_reap_expired_documents)
Actions
Copy link
 #1

Updated by mhrivnak over 8 years ago

  • Priority changed from Normal to High
  • Triaged changed from No to Yes
  • Tags Easy Fix added
Actions
Copy link
 #2

Updated by dkliban@redhat.com over 8 years ago

  • Status changed from NEW to ASSIGNED

Added by Dennis Kliban over 8 years ago

Revision 9400f33b | View on GitHub

Added import of tasks in the schedule manager

https://pulp.plan.io/issues/1154 fixes #1154

Added by Dennis Kliban over 8 years ago

Revision 9400f33b | View on GitHub

Added import of tasks in the schedule manager

https://pulp.plan.io/issues/1154 fixes #1154

Actions
Copy link
 #3

Updated by Anonymous over 8 years ago

  • Status changed from ASSIGNED to MODIFIED
  • % Done changed from 0 to 100
Actions
Copy link
 #4

Updated by dkliban@redhat.com over 8 years ago

A good way to reproduce this problem is to modify /etc/pulp/server.conf and set reaper_interval to 0.000694 or lower. This will cause the reaper task to run every minute or more frequently. After one minute the logs should then have output similar to this:

Aug 04 13:15:42 dev pulp[29048]: celery.beat:INFO: Scheduler: Sending due task reap_expired_documents (pulp.server.db.reaper.queue_reap_expired_documents)
Aug 04 13:15:42 dev pulp[28886]: celery.worker.strategy:INFO: Received task: pulp.server.db.reaper.queue_reap_expired_documents[4469180f-a36e-441c-863c-0590c33bd16e]
Aug 04 13:15:42 dev pulp[28884]: celery.worker.strategy:INFO: Received task: pulp.server.db.reaper.reap_expired_documents[c9a78be0-6283-4eaa-a78d-95c65880de6a]
Aug 04 13:15:42 dev pulp[28928]: pulp.server.db.reaper:INFO: The reaper task is cleaning out old documents from the database.
Aug 04 13:15:42 dev pulp[28928]: pulp.server.db.reaper:INFO: The reaper task has completed.
Actions
Copy link
 #5

Updated by dkliban@redhat.com over 8 years ago

  • Assignee set to dkliban@redhat.com
Actions
Copy link
 #6

Updated by dkliban@redhat.com over 8 years ago

  • Platform Release set to 2.8.0
Actions
Copy link
 #7

Updated by dkliban@redhat.com about 8 years ago

  • Status changed from MODIFIED to 5
Actions
Copy link
 #8

Updated by pthomas@redhat.com about 8 years ago

  • Status changed from 5 to 6

Verified


[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 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6236]: celery.beat:INFO: Scheduler: Sending due task 56d70cb1c6b14a1770d9621c (pulp.server.controllers.repository.queue_sync_with_auto_publish)
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6182]: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.queue_sync_with_auto_publish[977a031b-b867-460f-82e4-db66d4279991]
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6363]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[4138cdd9-b030-4ac6-9568-b679ccd4b928]
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6179]: celery.worker.strategy:INFO: Received task: pulp.server.managers.repo.sync.sync[1befcd39-cae0-41d2-943d-f31c47b0bdff]
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6182]: celery.worker.job:INFO: Task pulp.server.controllers.repository.queue_sync_with_auto_publish[977a031b-b867-460f-82e4-db66d4279991] succeeded in 0.0464620719431s: <AsyncResult: 1befcd39-cae0-41d2-943d-f31c47b0bdff>
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6179]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._release_resource[bf6117ff-e98d-423d-955b-79bf035102fe]
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6363]: celery.worker.job:INFO: Task pulp.server.async.tasks._queue_reserved_task[4138cdd9-b030-4ac6-9568-b679ccd4b928] succeeded in 0.0362234170316s: None
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading metadata from http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/.
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 11:08:00 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 11:08:01 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: Parsing metadata.
Mar 02 11:08:01 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading metadata from http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/.
Mar 02 11:08:01 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 11:08:01 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 11:08:02 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: Parsing metadata.
Mar 02 11:08:02 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading metadata from http://repos.fedorapeople.org/repos/pulp/pulp/demo_repos/zoo/.
Mar 02 11:08:02 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 11:08:02 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 11:08:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: Parsing metadata.
Mar 02 11:08:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: upstream repo metadata has not changed. Skipping steps.
Mar 02 11:08:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading additional units.
Mar 02 11:08:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 11:08:03 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 11:08:04 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTP connection (1): repos.fedorapeople.org
Mar 02 11:08:04 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): repos.fedorapeople.org
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp_rpm.plugins.importers.yum.sync:INFO: Sync complete.
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6363]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[83aadbdd-5f41-409a-94b7-dc8b2dcc19b6]
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp.server.async.tasks:INFO: resetting consecutive failure count for schedule 56d70cb1c6b14a1770d9621c
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6179]: celery.worker.strategy:INFO: Received task: pulp.server.managers.repo.publish.publish[2652660e-1d92-4a62-9d87-79715c7f3f0c]
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6179]: celery.worker.job:INFO: Task pulp.server.managers.repo.sync.sync[1befcd39-cae0-41d2-943d-f31c47b0bdff] succeeded in 5.20192475396s: <pulp.server.async.tasks.TaskResult object at 0x3b7a9d0>
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6179]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._release_resource[399330a1-e336-48ba-bc8f-13c0338494a6]
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6363]: celery.worker.job:INFO: Task pulp.server.async.tasks._queue_reserved_task[83aadbdd-5f41-409a-94b7-dc8b2dcc19b6] succeeded in 0.037997687934s: None
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6179]: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[bf6117ff-e98d-423d-955b-79bf035102fe] succeeded in 0.0432484389748s: None
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: 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/2652660e-1d92-4a62-9d87-79715c7f3f0c/repodata/repomd.xml]
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6402]: pulp.server.async.tasks:INFO: resetting consecutive failure count for schedule 56d70cb1c6b14a1770d9621c
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6179]: celery.worker.job:INFO: Task pulp.server.managers.repo.publish.publish[2652660e-1d92-4a62-9d87-79715c7f3f0c] succeeded in 0.413644760032s: {'exception': None, 'repo_id': u'zoo', 'traceback': None, 'started': '2016-03-02T16:08:05Z', '_ns': u'repo_publish_results',...
Mar 02 11:08:05 mgmt3.rhq.lab.eng.bos.redhat.com pulp[6179]: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[399330a1-e336-48ba-bc8f-13c0338494a6] succeeded in 0.00933531799819s: None
Actions
Copy link
 #9

Updated by dkliban@redhat.com about 8 years ago

  • Status changed from 6 to CLOSED - CURRENTRELEASE
Actions
Copy link
 #11

Updated by bmbouter about 5 years ago

  • Tags Pulp 2 added
Actions
Send by e-mail Copy link

Also available in: Atom PDF