Celery error: “No module named billiard.forking” - how to diagnose?

Question

I have no idea where to start diagnosing and fixing this:

$  bin/django celeryd -l DEBUG -v 3


 -------------- celery@lucid32 v3.0.3 (Chiastic Slide)
---- **** ----- 
--- * ***  * -- [Configuration]
-- * - **** --- . broker:      django://localhost//
- ** ---------- . app:         default:0x8b0aa4c (djcelery.loaders.DjangoLoader)
- ** ---------- . concurrency: 1 (processes)
- ** ---------- . events:      OFF (enable -E to monitor this worker)
- ** ---------- 
- *** --- * --- [Queues]
-- ******* ---- . celery:      exchange:celery(direct) binding:celery
--- ***** ----- 

[Tasks]
  . celery.backend_cleanup
  . celery.chain
  . celery.chord
  . celery.chord_unlock
  . celery.chunks
  . celery.group
  . celery.map
  . celery.starmap
  . tardis_portal.make_local_copy
  . tardis_portal.verify_as_remote
  . tardis_portal.verify_files

[2012-07-25 18:27:37,168: DEBUG/MainProcess] [Worker] Loading modules.
[2012-07-25 18:27:37,173: DEBUG/MainProcess] [Worker] Claiming components.
[2012-07-25 18:27:37,173: DEBUG/MainProcess] [Worker] Building boot step graph.
[2012-07-25 18:27:37,173: DEBUG/MainProcess] [Worker] New boot order: {ev, queues, pool, mediator, beat, autoreloader, timers, state-db, autoscaler, consumer}
[2012-07-25 18:27:37,174: DEBUG/MainProcess] Starting celery.concurrency.processes.TaskPool...
[2012-07-25 18:27:37,229: DEBUG/MainProcess] celery.concurrency.processes.TaskPool OK!
[2012-07-25 18:27:37,233: DEBUG/MainProcess] Starting celery.worker.mediator.Mediator...
[2012-07-25 18:27:37,235: DEBUG/MainProcess] celery.worker.mediator.Mediator OK!
[2012-07-25 18:27:37,236: DEBUG/MainProcess] Starting celery.worker.consumer.BlockingConsumer...
[2012-07-25 18:27:37,236: WARNING/MainProcess] celery@lucid32 has started.
[2012-07-25 18:27:37,237: DEBUG/MainProcess] Consumer: Re-establishing connection to the broker...
[2012-07-25 18:27:37,242: DEBUG/MainProcess] Consumer: Connection established.
Traceback (most recent call last):
  File "<string>", line 1, in <module>
ImportError: No module named billiard.forking
[2012-07-25 18:27:37,287: DEBUG/MainProcess] Consumer: basic.qos: prefetch_count->4
[2012-07-25 18:27:37,298: DEBUG/MainProcess] Consumer: Ready to accept tasks!
Traceback (most recent call last):
  File "<string>", line 1, in <module>
ImportError: No module named billiard.forking
Traceback (most recent call last):
  File "<string>", line 1, in <module>
ImportError: No module named billiard.forking
...

I don't know what Billiard is, other than that it's some process multiforking component used by Django. Since there's so little context given I don't know whether I'm looking at an error in Django or in my app.

The appropriate forking.py is present in ./eggs/billiard-2.7.3.10-py2.6-linux-i686.egg/. Running bin/django shell then import billiard.forking executes correctly.

So, presumably some child process is being spawned with the wrong environment and not finding billiard.forking.

The application is here.

Answer 1

The ImportError is being raised from the subprocesses that billiard is creating when it forks. The ImportError is raised when those processes do not have billiard on their sys.path, which can happen in two cases that I know of right now.

The first, which is your case, happens because Django is mangling (and then un-mangling) the sys.path, as described in https://github.com/celery/billiard/issues/10. The workaround is to explicitly fix the sys.path as described in that thread.

The second, which is the case that happened to me, and caused me to find this question, is because you are in a virtualenv, and it is not being activated for the sub-process for some reason.

Celery (which is the thing that calls billiard) runs under "#!/usr/bin/env python2.6", so if your virtualenv was created without the python2.6 binary (maybe it only has 'python'), the subprocesses will fall back to using the system's python2.6, which will not have billiard installed. This can actually happen sometimes (and happened to me) - I have opened a pull request against virtualenv to hopefully remove some of those cases: https://github.com/pypa/virtualenv/pull/341

Answer 2

Ok, well I got over the first hurdle. The naive approach worked: grep the entire source tree, including eggs, for "billiard.forking". Surprisingly, the only place that it appears is inside the forking module itself:

if getattr(sys, 'frozen', False):
    return [sys.executable, '--billiard-fork']
else:
    prog = 'from billiard.forking import main; main()'
    return [_python_exe, '-c', prog, '--billiard-fork']

This is definitely the cause. At run time, that code returns this:

/usr/bin/python -c "from billiard.forking import main; main()" --billiard-fork

Which, predictably:

Traceback (most recent call last):
  File "<string>", line 1, in <module>
ImportError: No module named billiard.forking

I don't know why, or what this code is meant to do, but I'm past the "I have no idea where to begin" stage.