Bug 1121730

Summary: Task cancel results in unhandled exception
Product: [Retired] Pulp Reporter: Jeff Ortel <jortel>
Component: async/tasksAssignee: pulp-bugs
Status: CLOSED WORKSFORME QA Contact: pulp-qe-list
Severity: unspecified Docs Contact:
Priority: medium    
Version: 2.4 BetaCC: bmbouter, skarmark
Target Milestone: ---Keywords: Triaged
Target Release: 2.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-08-28 18:35:19 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Jeff Ortel 2014-07-21 17:54:26 UTC 
Description of problem:

Cancelling a repo sync task results in unhandled exception.

Output:

[jortel@localhost pulp_rpm]$ pulp-admin tasks cancel --task-id=a3207cd8-1b51-4a24-827d-7f2618d2b415
An internal error occurred on the Pulp server:

RequestException: DELETE request
on /pulp/api/v2/tasks/a3207cd8-1b51-4a24-827d-7f2618d2b415/ failed with 500 -
Task is already in a complete state: a3207cd8-1b51-4a24-827d-7f2618d2b415


Log:

Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR: Task pulp.server.async.tasks._reserve_resource[08318c43-e51d-464a-ac74-e10009ff7251] raised unexpected: NoWorkers()
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR: Traceback (most recent call last):
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR:   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR:     R = retval = fun(*args, **kwargs)
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR:   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in __protected_call__
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR:     return self.run(*args, **kwargs)
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR:   File "/home/jortel/git/pulp/server/pulp/server/async/tasks.py", line 126, in _reserve_resource
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR:     reserved_resource.assigned_queue = resources.get_least_busy_worker().queue_name
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR:   File "/home/jortel/git/pulp/server/pulp/server/managers/resources.py", line 39, in get_least_busy_worker
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR:     raise exceptions.NoWorkers()
Jul 21 11:49:54 localhost pulp: celery.worker.job:ERROR: NoWorkers: There are no Celery workers found in the system for reserved task work. Please ensure that there is at least one Celery worker running, and that the celerybeat service is also running.

Task List:
...
Operations:  sync
Resources:   el7 (repository)
State:       Cancelled
Start Time:  Unstarted
Finish Time: Incomplete
Task Id:     3b847064-4128-4c7b-b61e-9342ab288d63

Operations:  sync
Resources:   el7 (repository)
State:       Running
Start Time:  2014-07-21T17:27:28Z
Finish Time: Incomplete
Task Id:     a3207cd8-1b51-4a24-827d-7f2618d2b415

$ ps -ef | grep pulp

[jortel@localhost pulp_rpm]$ ps -ef | grep pulp
apache    2345   783  0 03:18 ?        00:00:40 (wsgi:pulp)     -DFOREGROUND
apache    2346   783  0 03:18 ?        00:00:40 (wsgi:pulp)     -DFOREGROUND
apache    2347   783  0 03:18 ?        00:00:40 (wsgi:pulp)     -DFOREGROUND
apache   21649     1  0 12:26 ?        00:00:05 /usr/bin/python /usr/bin/celery worker -A pulp.server.async.app -n resource_manager@%h -Q resource_manager -c 1 --events --umask 18
apache   21669 21649  0 12:26 ?        00:00:00 /usr/bin/python /usr/bin/celery worker -A pulp.server.async.app -n resource_manager@%h -Q resource_manager -c 1 --events --umask 18
apache   21676     1  1 12:26 ?        00:00:16 /usr/bin/python /usr/bin/celery beat --scheduler=pulp.server.async.scheduler.Scheduler
apache   23026     1  0 12:43 ?        00:00:02 /usr/bin/python /usr/bin/celery worker -n reserved_resource_worker-0@%h -A pulp.server.async.app -c 1 --events --umask 18
apache   23028     1  0 12:43 ?        00:00:02 /usr/bin/python /usr/bin/celery worker -n reserved_resource_worker-1@%h -A pulp.server.async.app -c 1 --events --umask 18
apache   23030     1  0 12:43 ?        00:00:02 /usr/bin/python /usr/bin/celery worker -n reserved_resource_worker-2@%h -A pulp.server.async.app -c 1 --events --umask 18
apache   23032     1  0 12:43 ?        00:00:02 /usr/bin/python /usr/bin/celery worker -n reserved_resource_worker-3@%h -A pulp.server.async.app -c 1 --events --umask 18
apache   23110 23026  0 12:43 ?        00:00:00 /usr/bin/python /usr/bin/celery worker -n reserved_resource_worker-0@%h -A pulp.server.async.app -c 1 --events --umask 18
apache   23111 23028  0 12:43 ?        00:00:00 /usr/bin/python /usr/bin/celery worker -n reserved_resource_worker-1@%h -A pulp.server.async.app -c 1 --events --umask 18
apache   23112 23032  0 12:43 ?        00:00:00 /usr/bin/python /usr/bin/celery worker -n reserved_resource_worker-3@%h -A pulp.server.async.app -c 1 --events --umask 18
apache   23113 23030  0 12:43 ?        00:00:00 /usr/bin/python /usr/bin/celery worker -n reserved_resource_worker-2@%h -A pulp.server.async.app -c 1 --events --umask 18
jortel   23251  3932  0 12:47 pts/0    00:00:00 grep --color=auto pulp
[jortel@localhost pulp_rpm]$ 

[root@localhost .ssh]# qpid-stat -q
Queues
  queue                                                           dur  autoDel  excl  msg   msgIn  msgOut  bytes  bytesIn  bytesOut  cons  bind
  ===============================================================================================================================================

 reserved_resource_worker-0@localhost.localdomain.celery.pidbox       Y                 0     0      0       0      0        0         1     2
  reserved_resource_worker-0@localhost.localdomain.dq             Y    Y                 0     0      0       0      0        0         1     2
  reserved_resource_worker-1@localhost.localdomain.celery.pidbox       Y                 0     0      0       0      0        0         1     2
  reserved_resource_worker-1@localhost.localdomain.dq             Y    Y                 0     0      0       0      0        0         1     2
  reserved_resource_worker-2@localhost.localdomain.celery.pidbox       Y                 0     0      0       0      0        0         1     2
  reserved_resource_worker-2@localhost.localdomain.dq             Y    Y                 0     0      0       0      0        0         1     2
  reserved_resource_worker-3@localhost.localdomain.celery.pidbox       Y                 0     0      0       0      0        0         1     2
  reserved_resource_worker-3@localhost.localdomain.dq             Y    Y                 0     0      0       0      0        0         1     2
  resource_manager                                                Y    Y                 0     9      9       0   8.14k    8.14k        1     2
  resource_manager@localhost.localdomain.celery.pidbox                 Y                 0     3      3       0   1.55k    1.55k        1     2
  resource_manager@localhost.localdomain.dq                       Y    Y                 0     0      0       0      0        0         1     2
Comment 1 Brian Bouterse 2014-08-21 15:17:16 UTC 
I could not reproduce this; moving it back to NEW
Comment 2 Jeff Ortel 2014-08-21 19:12:32 UTC 
IIRC, bmbouter resolved this by killing pulp service zombies.  I still think there is something to be resolved here but not a blocker for 2.4.1 since there is a workaround.

1. kill zombies
2. restart pulp services.
Comment 3 Brian Bouterse 2014-08-28 18:35:19 UTC 
This issue hasn't been seen by the reporter in a while, and I was unable to reproduce it. I'm closing for now, but we can reopen if it shows up again.