10

I've been trying to follow the Celery First Steps With Celery and Next Steps guides. My setup is Windows 7 64-bit, Anaconda Python 2.7 (32-bit), Installed Erlang 32-bit binaries, RabbitMQ server, and celery (with pip install celery).

Following the guide I created a proj folder with init.py, tasks.py, and celery.py. My init.py is empty. Here's celery.py:

from __future__ import absolute_import

from celery import Celery

app = Celery('proj',
             broker='amqp://',
             backend='amqp://',
             include=['proj.tasks'])

#Optional configuration, see the application user guide
app.conf.update(
    CELERY_TASK_RESULT_EXPIRES=3600,
    CELERY_TASK_SERIALIZER='json',
    CELERY_ACCEPT_CONTENT=['json'],  # Ignore other content
    CELERY_RESULT_SERIALIZER='json',
)

if __name__ == '__main__':
    app.start()

And here's tasks.py:

from __future__ import absolute_import

from .celery import app

@app.task
def add(x, y):
    return x + y


@app.task
def mul(x, y):
    return x * y


@app.task
def xsum(numbers):
    return sum(numbers)

First I understand I should make sure the RabbitMQ service is running. The Services tab of the Task Manger shows RabbitMQ is indeed running. To begin the celery server and load my tasks I open cmd.exe, navigate to the parent of proj (a folder I called celery_demo), and run this:

celery -A proj.celery worker -l debug

which gives this output:

C:\Users\bnables\Documents\Python\celery_demo>celery -A proj.celery worker -l debug
[2014-08-25 17:00:09,308: DEBUG/MainProcess] | Worker: Preparing bootsteps.
[2014-08-25 17:00:09,313: DEBUG/MainProcess] | Worker: Building graph...
[2014-08-25 17:00:09,315: DEBUG/MainProcess] | Worker: New boot order: {Timer, Hub, Queues (intra), Pool, Autoreloader, Autoscaler, StateDB, Beat, Con
sumer}
[2014-08-25 17:00:09,322: DEBUG/MainProcess] | Consumer: Preparing bootsteps.
[2014-08-25 17:00:09,322: DEBUG/MainProcess] | Consumer: Building graph...
[2014-08-25 17:00:09,332: DEBUG/MainProcess] | Consumer: New boot order: {Connection, Events, Heart, Mingle, Gossip, Tasks, Control, Agent, event loop
}

 -------------- celery@MSSLW40013047 v3.1.13 (Cipater)
---- **** -----
--- * ***  * -- Windows-7-6.1.7601-SP1
-- * - **** ---
- ** ---------- [config]
- ** ---------- .> app:         proj:0x3290370
- ** ---------- .> transport:   amqp://guest:**@localhost:5672//
- ** ---------- .> results:     amqp
- *** --- * --- .> concurrency: 8 (prefork)
-- ******* ----
--- ***** ----- [queues]
 -------------- .> celery           exchange=celery(direct) key=celery


[tasks]
  . celery.backend_cleanup
  . celery.chain
  . celery.chord
  . celery.chord_unlock
  . celery.chunks
  . celery.group
  . celery.map
  . celery.starmap
  . proj.tasks.add
  . proj.tasks.mul
  . proj.tasks.xsum

[2014-08-25 17:00:09,345: DEBUG/MainProcess] | Worker: Starting Pool
[2014-08-25 17:00:09,417: DEBUG/MainProcess] ^-- substep ok
[2014-08-25 17:00:09,420: DEBUG/MainProcess] | Worker: Starting Consumer
[2014-08-25 17:00:09,421: DEBUG/MainProcess] | Consumer: Starting Connection
[2014-08-25 17:00:09,457: DEBUG/MainProcess] Start from server, version: 0.9, properties: {u'information': u'Licensed under the MPL.  See http://www.r
abbitmq.com/', u'product': u'RabbitMQ', u'copyright': u'Copyright (C) 2007-2014 GoPivotal, Inc.', u'capabilities': {u'exchange_exchange_bindings': Tru
e, u'connection.blocked': True, u'authentication_failure_close': True, u'basic.nack': True, u'per_consumer_qos': True, u'consumer_priorities': True, u
'consumer_cancel_notify': True, u'publisher_confirms': True}, u'cluster_name': u'rabbit@MSSLW40013047.ndc.nasa.gov', u'platform': u'Erlang/OTP', u'ver
sion': u'3.3.5'}, mechanisms: [u'AMQPLAIN', u'PLAIN'], locales: [u'en_US']
[2014-08-25 17:00:09,460: DEBUG/MainProcess] Open OK!
[2014-08-25 17:00:09,460: INFO/MainProcess] Connected to amqp://guest:**@127.0.0.1:5672//
[2014-08-25 17:00:09,461: DEBUG/MainProcess] ^-- substep ok
[2014-08-25 17:00:09,461: DEBUG/MainProcess] | Consumer: Starting Events
[2014-08-25 17:00:09,516: DEBUG/MainProcess] Start from server, version: 0.9, properties: {u'information': u'Licensed under the MPL.  See http://www.r
abbitmq.com/', u'product': u'RabbitMQ', u'copyright': u'Copyright (C) 2007-2014 GoPivotal, Inc.', u'capabilities': {u'exchange_exchange_bindings': Tru
e, u'connection.blocked': True, u'authentication_failure_close': True, u'basic.nack': True, u'per_consumer_qos': True, u'consumer_priorities': True, u
'consumer_cancel_notify': True, u'publisher_confirms': True}, u'cluster_name': u'rabbit@MSSLW40013047.ndc.nasa.gov', u'platform': u'Erlang/OTP', u'ver
sion': u'3.3.5'}, mechanisms: [u'AMQPLAIN', u'PLAIN'], locales: [u'en_US']
[2014-08-25 17:00:09,519: DEBUG/MainProcess] Open OK!
[2014-08-25 17:00:09,520: DEBUG/MainProcess] using channel_id: 1
[2014-08-25 17:00:09,522: DEBUG/MainProcess] Channel open
[2014-08-25 17:00:09,523: DEBUG/MainProcess] ^-- substep ok
[2014-08-25 17:00:09,523: DEBUG/MainProcess] | Consumer: Starting Heart
[2014-08-25 17:00:09,530: DEBUG/MainProcess] ^-- substep ok
[2014-08-25 17:00:09,533: DEBUG/MainProcess] | Consumer: Starting Mingle
[2014-08-25 17:00:09,538: INFO/MainProcess] mingle: searching for neighbors
[2014-08-25 17:00:09,539: DEBUG/MainProcess] using channel_id: 1
[2014-08-25 17:00:09,540: DEBUG/MainProcess] Channel open
[2014-08-25 17:00:10,552: INFO/MainProcess] mingle: all alone
[2014-08-25 17:00:10,552: DEBUG/MainProcess] ^-- substep ok
[2014-08-25 17:00:10,552: DEBUG/MainProcess] | Consumer: Starting Gossip
[2014-08-25 17:00:10,553: DEBUG/MainProcess] using channel_id: 2
[2014-08-25 17:00:10,555: DEBUG/MainProcess] Channel open
[2014-08-25 17:00:10,559: DEBUG/MainProcess] ^-- substep ok
[2014-08-25 17:00:10,559: DEBUG/MainProcess] | Consumer: Starting Tasks
[2014-08-25 17:00:10,566: DEBUG/MainProcess] ^-- substep ok
[2014-08-25 17:00:10,566: DEBUG/MainProcess] | Consumer: Starting Control
[2014-08-25 17:00:10,568: DEBUG/MainProcess] using channel_id: 3
[2014-08-25 17:00:10,569: DEBUG/MainProcess] Channel open
[2014-08-25 17:00:10,572: DEBUG/MainProcess] ^-- substep ok
[2014-08-25 17:00:10,573: DEBUG/MainProcess] | Consumer: Starting event loop
[2014-08-25 17:00:10,575: WARNING/MainProcess] celery@MSSLW40013047 ready.
[2014-08-25 17:00:10,575: DEBUG/MainProcess] basic.qos: prefetch_count->32

The -A tells celery where to find my celery app instance. Using just proj works too, but since it will then just search for proj.celery, being more explicit is fine here. worker is the command given to celery telling it to spawn some workers for executing the tasks it loads from proj.celery. Finally -l debug tells celery to set the log level to debug so that I get lots of information. This would normally be -l info.

In order to test my task server I open an IPython Qt Console and navigate to the celery_demo folder (which contains proj). I then type from proj.tasks import add. Simply invoking add(1, 2) returns 3 without utilizing the server, as expected. When I invoke add.delay this is what happens:

add.delay(2, 3)

Which returns:

<AsyncResult: 42123ff3-e94e-4673-808a-ec6c847679d8>

And in my cmd.exe window I get:

[2014-08-25 17:20:38,109: INFO/MainProcess] Received task: proj.tasks.add[42123ff3-e94e-4673-808a-ec6c847679d8]
[2014-08-25 17:20:38,109: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x033CD6F0> (args:(u'proj.tasks.add', u'42123ff3-e94e-4673-
808a-ec6c847679d8', [2, 3], {}, {u'timelimit': [None, None], u'utc': True, u'is_eager': False, u'chord': None, u'group': None, u'args': [2, 3], u'retr
ies': 0, u'delivery_info': {u'priority': None, u'redelivered': False, u'routing_key': u'celery', u'exchange': u'celery'}, u'expires': None, u'hostname
': 'celery@MSSLW40013047', u'task': u'proj.tasks.add', u'callbacks': None, u'correlation_id': u'42123ff3-e94e-4673-808a-ec6c847679d8', u'errbacks': No
ne, u'reply_to': u'70ed001d-193c-319c-9447-8d77c231dc10', u'taskset': None, u'kwargs': {}, u'eta': None, u'id': u'42123ff3-e94e-4673-808a-ec6c847679d8
', u'headers': {}}) kwargs:{})
[2014-08-25 17:20:38,124: DEBUG/MainProcess] Task accepted: proj.tasks.add[42123ff3-e94e-4673-808a-ec6c847679d8] pid:4052
[2014-08-25 17:20:38,125: INFO/MainProcess] Task proj.tasks.add[42123ff3-e94e-4673-808a-ec6c847679d8] succeeded in 0.0130000114441s: 5

So as the last line shows, the result of 5 is being calculated. Next I want to store the AsyncResult object and check it's state and get the result value:

result = add.delay(3, 4)

However result.state and result.get(timeout=1) don't work as expected:

In:  result.state
Out: 'Pending'
In:  result.status
Out: 'Pending'

In: result.get(timeout=1)
---------------------------------------------------------------------------
TimeoutError                              Traceback (most recent call last)
<ipython-input-17-375f2d3530cb> in <module>()
----> 1 result.get(timeout=1)

C:\Anaconda32\lib\site-packages\celery\result.pyc in get(self, timeout, propagate, interval, no_ack, follow_parents)
    167                 interval=interval,
    168                 on_interval=on_interval,
--> 169                 no_ack=no_ack,
    170             )
    171         finally:

C:\Anaconda32\lib\site-packages\celery\backends\amqp.pyc in wait_for(self, task_id, timeout, cache, propagate, no_ack, on_interval, READY_STATES, PROPAGATE_STATES, **kwargs)
    155                                     on_interval=on_interval)
    156             except socket.timeout:
--> 157                 raise TimeoutError('The operation timed out.')
    158 
    159         if meta['status'] in PROPAGATE_STATES and propagate:

TimeoutError: The operation timed out.

Where the expected result of result.state or result.status is 'SUCCESSFUL', and the result of result.get(timeout=1) should be 5.

It appears the result storage or message passing isn't working correctly. The tutorial simply says setting the backend named parameter in the call to Celery() or the CELERY_RESULT_BACKEND config setting. In 'getting started' it has backend='amqp' where the 'Next Steps' has backend='amqp://' which is also used in the github examples.

I've been banging my head on this for a while with little clue of how to proceed. Any ideas on what to try next? Thanks!

flutefreak7
  • 2,321
  • 5
  • 29
  • 39

3 Answers3

22
  • W8 x64
  • Python 2.7.3 (ActivePython)
  • Erlang 17.1 x64
  • RabbitMQ server 3.3.5
  • Celery 3.1.13

Randomly stopped working too. Exact same problem - forever pending. Reinstalling Erlang or RabbitMQ didn't help.

I tested also on Debian Linux 7 x86 and here it's working fine without problems.

Also: https://github.com/celery/celery/issues/2146

It's propably Windows related problem and setting worker flag --pool=solo fixed it for me ATM

user3664862
  • 298
  • 1
  • 8
  • Thanks! Makes sense 'prefork' would have trouble under Windows ([b/c no os.fork](https://docs.python.org/2/library/multiprocessing.html#windows))... It appears celery checks for that in [billiard.forking_enable()](https://github.com/celery/billiard/blob/master/billiard/__init__.py#L306) ... [billiard.forking](https://github.com/celery/billiard/blob/master/billiard/forking.py) has entirely different Popen classes for Windows, but I get lost trying to understand billiard.pool & celery.concurancy.prefork. Perhaps something shared through forking on Linux is misplaced on Windows... – flutefreak7 Aug 26 '14 at 15:09
  • thanks you , i have such issue, so i put flag --pool=solo fixed it – rogers.wang Apr 16 '20 at 23:07
5

You must add track_started=True. Well, it's hard to know this option.

The default value is False, so you will always get PENDING when the task is not finished. Besides, you must config wrong on backend or broker. Plz check them again.

@app.task(bind=True, track_started=True)
def add(self, x, y):
    return x + y
Fred
  • 417
  • 6
  • 14
chris
  • 2,761
  • 17
  • 24
  • 1
    `TypeError: add() takes 2 positional arguments but 3 were given` – am.rez Jan 03 '21 at 06:24
  • @am.rez note that this example was probably a bit out of context. Apparently this comes from a method of a class. If you have a method on module level remove `bind=True` from the decorator and `self` from the signature. – grmmgrmm Nov 05 '21 at 15:47
2

.delay methods puts your task in queue. "result.state" is showing pending, which means your task in not yet executed. There might be a lot tasks, so its getting delayed.

Check if there are any tasks running

>>> from celery.task.control import inspect
>>> i = inspect()
>>> i.scheduled()
>>> i.active()
Chillar Anand
  • 27,936
  • 9
  • 119
  • 136
  • The log output coming from celery assure me that my 2+3 task completes and succeeds with a result of 5. Also a simple math task shouldn't cause it to clog up or take forever, of course, me saying 'it should work' doesn't solve anything. Thanks for the `inspect` tips though - I hadn't learned about that stuff yet! – flutefreak7 Aug 26 '14 at 15:14