Project

Profile

Help

Issue #1154

scheduled tasks fail to run

Added by dkliban@redhat.com almost 6 years ago. Updated about 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:
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)

Associated revisions

Revision 9400f33b View on GitHub
Added by Dennis Kliban almost 6 years ago

Added import of tasks in the schedule manager

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

Revision 9400f33b View on GitHub
Added by Dennis Kliban almost 6 years ago

Added import of tasks in the schedule manager

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

History

#1 Updated by mhrivnak almost 6 years ago

  • Priority changed from Normal to High
  • Triaged changed from No to Yes
  • Tags Easy Fix added

#2 Updated by dkliban@redhat.com almost 6 years ago

  • Status changed from NEW to ASSIGNED

#3 Updated by Anonymous almost 6 years ago

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

#4 Updated by dkliban@redhat.com almost 6 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.

#5 Updated by dkliban@redhat.com almost 6 years ago

  • Assignee set to dkliban@redhat.com

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

  • Platform Release set to 2.8.0

#7 Updated by dkliban@redhat.com about 5 years ago

  • Status changed from MODIFIED to 5

#8 Updated by pthomas@redhat.com about 5 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

#9 Updated by dkliban@redhat.com about 5 years ago

  • Status changed from 6 to CLOSED - CURRENTRELEASE

#11 Updated by bmbouter about 2 years ago

  • Tags Pulp 2 added

Please register to edit this issue

Also available in: Atom PDF