Wu Haotian

Posted on Apr 12, 2020 • Edited on Apr 15, 2020 • Originally published at blog.whtsky.me

Fixing Django's "populate() isn't reentrant" by printing traceback

#python #django #celery #traceback

Note: This article is based on Django 2.2.11

I was maintaining a huge Django app. Everything looked fine until I tried to run python manage.py -h:

Traceback (most recent call last):
  File "manage.py", line 15, in <module>
    execute_from_command_line(sys.argv)
  File "venv/lib/python3.6/site-packages/django/core/management/__init__.py", line 381, in execute_from_command_line
    utility.execute()
  File "venv/lib/python3.6/site-packages/django/core/management/__init__.py", line 357, in execute
    django.setup()
  File "venv/lib/python3.6/site-packages/django/__init__.py", line 24, in setup
    apps.populate(settings.INSTALLED_APPS)
  File "venv/lib/python3.6/site-packages/django/apps/registry.py", line 83, in populate
    raise RuntimeError("populate() isn't reentrant")
RuntimeError: populate() isn't reentrant

Hmmm, okay.

The exception was from execute_from_command_line in manage.py, which is generated by Django thus in great chance not the root cause of the exception.
I googled populate() isn't reentrant but the results weren't helpful enough to me.

Let's dig into Django's source code then. Followed the traceback from exception we can locate the populate function

# An RLock prevents other threads from entering this section. The
# compare and set operation below is atomic.
if self.loading:
    # Prevent reentrant calls to avoid running AppConfig.ready()
    # methods twice.
    raise RuntimeError("populate() isn't reentrant")
self.loading = True

Looks like the populate got called twice. Since execute_from_command_line is expected, let's record the traceback from the other call and print it out.

Modify venv/lib/python3.6/site-packages/django/apps/registry.py:

# An RLock prevents other threads from entering this section. The
# compare and set operation below is atomic.
if self.loading:
    # Prevent reentrant calls to avoid running AppConfig.ready()
    # methods twice.
    raise RuntimeError("populate() isn't reentrant.\n" + "\n".join(self.prev_traceback))
self.loading = True
import traceback
self.prev_traceback = traceback.format_stack()

Rerun python manage.py -h, and we can see the nice traceback.

  File "server/__init__.py", line 1, in <module>
    from .celery import app as celery_app

  File "<frozen importlib._bootstrap>", line 971, in _find_and_load

  File "<frozen importlib._bootstrap>", line 955, in _find_and_load_unlocked

  File "<frozen importlib._bootstrap>", line 665, in _load_unlocked

  File "<frozen importlib._bootstrap_external>", line 678, in exec_module

  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed

  File "server/celery.py", line 11, in <module>
    django.setup()

  File "venv/lib/python3.6/site-packages/django/__init__.py", line 24, in setup
    apps.populate(settings.INSTALLED_APPS)

  File "venv/lib/python3.6/site-packages/django/apps/registry.py", line 85, in populate
    self.prev_traceback = traceback.format_stack()

Looks like someone called django.setup() in our celery module.

# set the default Django settings module for the 'celery' program.
os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'balisong_server.settings')
django.setup()

app = Celery('balisong')

After talking with the code author and looking into celery's document, I'm definite that the django.setup() here should be removed.
And removing this solves the problem.

Lessons learned: when in doubt, just print traceback.

Originally published at https://blog.whtsky.me/tech/2020/populate_isnt_reentrant/