I am trying to use django + celery + djcelery + rabbitmq + memcached to offload synchronous tasks to other servers.
According to both celery log and celery flower, the async task is sent to the worker and executes successfully. However the result it seems never returns.
The code running on the web server is:
def wait_task(task, *args):
async_result = task.delay(*args)
return async_result.get()
@shared_task(serializer="pickle")
def render_pdf(pdf_id):
pdf = do_stuff()
return pdf
pdf = wait_task(render_pdf, pdf_id)
My BROKER_URL is set to librabbitmq://guest:[email protected]:5672/ which is honoured as evidenced by the celery log and celery flower output.
The truncated result shown in celery flower is reminiscent of a successfully rendered PDF.
/etc/rabbitmq/rabbitmq-env.conf is:
NODENAME=rabbit@localhost
NODE_IP_ADDRESS=0.0.0.0
Not really sure where to look next. Assuming that either celery is not returning/calling back to rabbitmq, or rabbitmq is not returning/calling back to the original wait_task invocation.
If I run the web server on the same VM as the broker however then everything works fine, even with the same BROKER_URL. Somewhere in the configuration I suppose it is making an assumption with where to call back to, such as localhost/127.0.0.1 or something?
UPDATE 1:
Celery log output from startup to first shared task completion:
[2016-02-02 23:54:07,786: DEBUG/MainProcess] | Worker: Preparing bootsteps.
[2016-02-02 23:54:07,792: DEBUG/MainProcess] | Worker: Building graph...
[2016-02-02 23:54:07,793: DEBUG/MainProcess] | Worker: New boot order: {StateDB, Timer, Hub, Queues (intra), Pool, Autoreloader, Beat, Autoscaler, Consumer}
[2016-02-02 23:54:07,796: DEBUG/MainProcess] | Consumer: Preparing bootsteps.
[2016-02-02 23:54:07,797: DEBUG/MainProcess] | Consumer: Building graph...
[2016-02-02 23:54:07,799: DEBUG/MainProcess] | Consumer: New boot order: {Connection, Events, Mingle, Gossip, Tasks, Control, Agent, Heart, event loop}
[2016-02-02 23:54:07,806: DEBUG/MainProcess] | Worker: Starting Hub
[2016-02-02 23:54:07,807: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:07,807: DEBUG/MainProcess] | Worker: Starting Pool
[2016-02-02 23:54:07,811: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:07,813: DEBUG/MainProcess] | Worker: Starting Autoscaler
[2016-02-02 23:54:07,813: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:07,814: DEBUG/MainProcess] | Worker: Starting Consumer
[2016-02-02 23:54:07,815: DEBUG/MainProcess] | Consumer: Starting Connection
[2016-02-02 23:54:07,824: INFO/MainProcess] Connected to amqp://guest:**@172.17.0.5:5672//
[2016-02-02 23:54:07,825: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:07,826: DEBUG/MainProcess] | Consumer: Starting Events
[2016-02-02 23:54:07,836: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:07,837: DEBUG/MainProcess] | Consumer: Starting Mingle
[2016-02-02 23:54:07,838: INFO/MainProcess] mingle: searching for neighbors
[2016-02-02 23:54:08,848: INFO/MainProcess] mingle: all alone
[2016-02-02 23:54:08,850: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:08,851: DEBUG/MainProcess] | Consumer: Starting Gossip
[2016-02-02 23:54:08,855: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:08,856: DEBUG/MainProcess] | Consumer: Starting Tasks
[2016-02-02 23:54:08,862: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:08,863: DEBUG/MainProcess] | Consumer: Starting Control
[2016-02-02 23:54:08,867: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:08,868: DEBUG/MainProcess] | Consumer: Starting Heart
[2016-02-02 23:54:08,870: DEBUG/MainProcess] ^-- substep ok
[2016-02-02 23:54:08,871: DEBUG/MainProcess] | Consumer: Starting event loop
[2016-02-02 23:54:08,873: DEBUG/MainProcess] /virtualenv/processing/local/lib/python2.7/site-packages/celery/fixups/django.py:265: UserWarning: Using settings.DEBUG leads to a memory leak, never use this setting in production environments!
warnings.warn('Using settings.DEBUG leads to a memory leak, never '
[2016-02-02 23:54:08,875: DEBUG/MainProcess] [email protected] ready.
[2016-02-02 23:54:08,876: DEBUG/MainProcess] | Worker: Hub.register Autoscaler...
[2016-02-02 23:54:08,877: DEBUG/MainProcess] | Worker: Hub.register Pool...
[2016-02-02 23:54:08,878: DEBUG/MainProcess] basic.qos: prefetch_count->1
[2016-02-02 23:54:13,263: INFO/MainProcess] Received task: tasks.render_pdf[149cc075-1d09-4547-86ee-57608c1df8aa]
[2016-02-02 23:54:13,265: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x7f08fccd7488> (args:('tasks.render_pdf', '149cc075-1d09-4547-86ee-57608c1df8aa', (u'en', 8583L), {}, {'utc': True, u'is_eager': False, 'chord': None, u'group': None, 'args': (u'en', 8583L), 'retries': 0, u'delivery_info': {u'priority': None, u'redelivered': False, u'routing_key': 'default', u'exchange': 'default'}, 'expires': None, u'hostname': '[email protected]', 'task': 'tasks.render_pdf', 'callbacks': None, u'correlation_id': '149cc075-1d09-4547-86ee-57608c1df8aa', 'errbacks': None, 'timelimit': (None, None), 'taskset': None, 'kwargs': {}, 'eta': None, u'reply_to': '8502acac-0475-3f84-b542-03fdf4ea4d3d', 'id': '149cc075-1d09-4547-86ee-57608c1df8aa', u'headers': {}}) kwargs:{})
[2016-02-02 23:54:13,267: DEBUG/MainProcess] Task accepted: tasks.render_pdf[149cc075-1d09-4547-86ee-57608c1df8aa] pid:5033
[2016-02-02 23:54:14,193: INFO/MainProcess] Task tasks.render_pdf[149cc075-1d09-4547-86ee-57608c1df8aa] succeeded in 0.926254872s: '%PDF-1.4\n1 0 obj\n<<\n/Title (\xfe\xff\x00T\x00i\x00c\x00k\x00e\x00t\x00f\x00l\x00a\x00p\x00...
UPDATE 2:
Cache settings:
CELERY_RESULT_BACKEND = 'djcelery.backends.cache:CacheBackend'
MEMCACHED_HOST = '172.17.0.5'
MEMCACHED_PORT = 11211
CACHES = {
'default': {
'BACKEND': 'django.core.cache.backends.memcached.MemcachedCache',
'LOCATION': '%s:%s' % (MEMCACHED_HOST, str(MEMCACHED_PORT)),
'TIMEOUT': 18000 # 5 hours
},
}
UPDATE 3:
Output in /var/logs/rabbitmq/[email protected]:
If I run celery and web server on separate instances which fails as above:
=INFO REPORT==== 2-Feb-2016::16:12:33 ===
accepting AMQP connection <0.469.0> (172.17.0.6:36786 -> 172.17.0.5:5672)
If I run celery and web server on the same instance which works fine:
=INFO REPORT==== 2-Feb-2016::16:13:09 ===
accepting AMQP connection <0.482.0> (172.17.0.5:33863 -> 172.17.0.5:5672)
