Error reporting returns a circular import error on a python formatting error, and does not restart the development server

[Runner15]

In Django 2.2.1, a python formatting error, such as a NameError or IndentationError will give the error shown below:

Exception in thread django-main-thread:
Traceback (most recent call last):
  File "/home/runner/.local/lib/python3.5/site-packages/django/urls/resolvers.py", line 581, in url_patterns
    iter(patterns)
TypeError: 'module' object is not iterable

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.5/threading.py", line 862, in run
    self._target(*self._args, **self._kwargs)
  File "/home/runner/.local/lib/python3.5/site-packages/django/utils/autoreload.py", line 54, in wrapper
    fn(*args, **kwargs)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/management/commands/runserver.py", line 117, in inner_run
    self.check(display_num_errors=True)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/management/base.py", line 390, in check
    include_deployment_checks=include_deployment_checks,
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/management/base.py", line 377, in _run_checks
    return checks.run_checks(**kwargs)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/checks/registry.py", line 72, in run_checks
    new_errors = check(app_configs=app_configs)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/checks/urls.py", line 13, in check_url_config
    return check_resolver(resolver)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/checks/urls.py", line 23, in check_resolver
    return check_method()
  File "/home/runner/.local/lib/python3.5/site-packages/django/urls/resolvers.py", line 398, in check
    for pattern in self.url_patterns:
  File "/home/runner/.local/lib/python3.5/site-packages/django/utils/functional.py", line 80, in __get__
    res = instance.__dict__[self.name] = self.func(instance)
  File "/home/runner/.local/lib/python3.5/site-packages/django/urls/resolvers.py", line 588, in url_patterns
    raise ImproperlyConfigured(msg.format(name=self.urlconf_name))
django.core.exceptions.ImproperlyConfigured: The included URLconf 'runnertest.urls' does not appear to have any patterns in it. If you see valid patterns in the file then the issue is probably caused by a circular import.

This throws django.core.exceptions.ImproperlyConfigured error, with the message that the main urls file does not appear to have any patters in it, and if there are patterns then the issue is probably a circular import.
Neither of these are the problem, as it is just a simple line in the code that is indented improperly, or a variable that is not assigned. When this issue is fixed, the development server does not restart itself to reflect this fix. It manually has to be quit and then restarted.

The code below is the same python formatting error in Django 2.1. It shows the error at the end of the error reporting, and when the error is fixed in the code, the development server restarts itself.

Unhandled exception in thread started by <function check_errors.<locals>.wrapper at 0x7f03cb1029d8>
Traceback (most recent call last):
  File "/home/runner/.local/lib/python3.5/site-packages/django/utils/autoreload.py", line 225, in wrapper
    fn(*args, **kwargs)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/management/commands/runserver.py", line 117, in inner_run
    self.check(display_num_errors=True)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/management/base.py", line 379, in check
    include_deployment_checks=include_deployment_checks,
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/management/base.py", line 366, in _run_checks
    return checks.run_checks(**kwargs)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/checks/registry.py", line 71, in run_checks
    new_errors = check(app_configs=app_configs)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/checks/urls.py", line 40, in check_url_namespaces_unique
    all_namespaces = _load_all_namespaces(resolver)
  File "/home/runner/.local/lib/python3.5/site-packages/django/core/checks/urls.py", line 57, in _load_all_namespaces
    url_patterns = getattr(resolver, 'url_patterns', [])
  File "/home/runner/.local/lib/python3.5/site-packages/django/utils/functional.py", line 37, in __get__
    res = instance.__dict__[self.name] = self.func(instance)
  File "/home/runner/.local/lib/python3.5/site-packages/django/urls/resolvers.py", line 533, in url_patterns
    patterns = getattr(self.urlconf_module, "urlpatterns", self.urlconf_module)
  File "/home/runner/.local/lib/python3.5/site-packages/django/utils/functional.py", line 37, in __get__
    res = instance.__dict__[self.name] = self.func(instance)
  File "/home/runner/.local/lib/python3.5/site-packages/django/urls/resolvers.py", line 526, in urlconf_module
    return import_module(self.urlconf_name)
  File "/usr/lib/python3.5/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 986, in _gcd_import
  File "<frozen importlib._bootstrap>", line 969, in _find_and_load
  File "<frozen importlib._bootstrap>", line 958, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 673, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 665, in exec_module
  File "<frozen importlib._bootstrap>", line 222, in _call_with_frames_removed
  File "/mnt/c/Users/myName/documents/python/django/runnertest/runnertest/urls.py", line 23, in <module>
    path('air/', include('appName.urls')),
  File "/home/runner/.local/lib/python3.5/site-packages/django/urls/conf.py", line 34, in include
    urlconf_module = import_module(urlconf_module)
  File "/usr/lib/python3.5/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 986, in _gcd_import
  File "<frozen importlib._bootstrap>", line 969, in _find_and_load
  File "<frozen importlib._bootstrap>", line 958, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 673, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 665, in exec_module
  File "<frozen importlib._bootstrap>", line 222, in _call_with_frames_removed
  File "/mnt/c/Users/myName/documents/python/django/runnertest/appName/urls.py", line 3, in <module>
    from . import views
  File "/mnt/c/Users/myName/documents/python/django/runnertest/appName/views.py", line 233, in <module>
    a
NameError: name 'a' is not defined

This can be replicated by adding an extra space on a line in your views file, or throwing a variable name that does not exist on its own line.

[Carlton Gibson]

This has been the case ≈forever I think. (A syntax error has always required a ^{-C and a restart.)}

Unless you have a specific patch to suggest this isn't something I want to accept as an active ticket.
(I would say wontfix but that's not quite right: if a small change comes along that does the right thing then great, so `needsinfo)

Please do reopen if you have a concrete suggestion, preferably as a PR. Thanks.

[Mariusz Felisiak]

It looks like a duplicate of #30323. I'm able to reproduce this in Django 2.2 but in 2.2.1 everything works as expected. See ​release notes:

Fixed a regression in Django 2.2 that caused a crash of runserver when URLConf modules raised exceptions (#30323).

[Runner15]

I have it reproduced in Django 2.2.1, as that is where the error message posted in the original ticket was from. It does not give the error location nor does it restart the development server.

Replying to felixxm:

It looks like a duplicate of #30323. I'm able to reproduce this in Django 2.2 but in 2.2.1 everything works as expected. See ​release notes:

Fixed a regression in Django 2.2 that caused a crash of runserver when URLConf modules raised exceptions (#30323).

[Keryn Knight]

Re-opening as I can reproduce the less-useful-exception in 2.2.1 vs 2.2 (via Python 3.6)

The correct error which should be surfaced is (2.1):

NameError: name 'a' is not defined

The error which is surfaced currently (2.2.1) is:

django.core.exceptions.ImproperlyConfigured: The included URLconf 't30500.urls' does not appear to have any patterns in it. If you see valid patterns in the file then the issue is probably caused by a circular import.

Example reproducible project is available: ​https://github.com/kezabelle/django-bug-30500
Steps to reproduce:

• runserver the project under 2.1
• Uncomment the "a" in "t30500/views.py" to trigger the reloader and the exception to stdout

Do the same under 2.2, and the error won't turn up.

[Mariusz Felisiak]

I still cannot reproduce this issue on Django 2.2.1 even with your tests project, I get correct exception (the same like with Django 2.1.)

  File "/tmp/django-bug-30500/t30500/urls2.py", line 1, in <module>
    from . import views
  File "/tmp/django-bug-30500/t30500/views.py", line 5, in <module>
    a
NameError: name 'a' is not defined

Are you using StatReloader or Watchman?

[Carlton Gibson]

OK, this reproduces for me using Python 3.6.0.

However, we only support the latest point release of each Python series, so currently 3.6.8. It works there.

Mariusz reports he tested against 3.6.3, where it also works.

Thus this is an issue in Python that was resolved some time before 3.6.3. (I'm pretty sure this always used to require a restart, so likely it changed around then.)

Thanks for the report and project to follow-up! I suggest updating Python to 3.6.8 (or 3.7 if you can.)

[Keryn Knight]

Verified the correct error message (NameError: name 'a' is not defined) turns up under Python 3.5.7, so I guess it is a non-issue overall (fwiw, I was verifying under 3.6.2, if Mariusz couldn't reproduce under 3.6.3, it got "fixed" upstream in that version).

(I would argue that the ergonomics of Django are harmed by not fixing this because it works in the officially-supported point releases, because it is more likely to mask problems affecting new users, who are learning Django but don't necessarily know the ecosystem well enough to install/maintain their own version (eg: by using system python, or whatever))

[Keryn Knight]

Actually with a bit of effort, I can still reproduce it under 3.5.7 at least, and I'm suspicious about it being a race condition/timing(/threading?) problem:

Given:

import time, os, random
>>> while True:
...    time.sleep(random.random())
...    os.utime('/path/to/t30500/t30500/views.py')

after some arbitrary period of leaving python -b -B manage.py runserver 0:8080 running, I can get it to do it:

[...] 
  File "/path/to/t30500/t30500/urls2.py", line 1, in <module>
    from . import views
  File "/path/to/t30500/t30500/views.py", line 3, in <module>
    a
NameError: name 'a' is not defined

/path/to/t30500/t30500/views.py changed, reloading.
Watching for file changes with StatReloader
Performing system checks...

Exception in thread django-main-thread:
Traceback (most recent call last):
  File "/path/to/lib/python3.5/site-packages/django/urls/resolvers.py", line 581, in url_patterns
    iter(patterns)
TypeError: 'module' object is not iterable

During handling of the above exception, another exception occurred:

[...]
File "/path/to/lib/python3.5/site-packages/django/core/checks/urls.py", line 57, in _load_all_namespaces
    url_patterns = getattr(resolver, 'url_patterns', [])
  File "/path/to/lib/python3.5/site-packages/django/utils/functional.py", line 80, in __get__
    res = instance.__dict__[self.name] = self.func(instance)
  File "/path/to/lib/python3.5/site-packages/django/urls/resolvers.py", line 588, in url_patterns
    raise ImproperlyConfigured(msg.format(name=self.urlconf_name))
django.core.exceptions.ImproperlyConfigured: The included URLconf 't30500.urls' does not appear to have any patterns in it. If you see valid patterns in the file then the issue is probably caused by a circular import.

If it is some form of timing problem, it could be that it has always existed, but the move to Pathlib has made this specific occurrence more visible because it's slower, and possibly it's visibility changes between python versions (I can't say I've tracked if it's been optimised in 3.6+) for that reason too.

I don't know. None of it is particularly clear cut; these kinds of things never are.

[Carlton Gibson]

I would argue that the ergonomics of Django are harmed...

I totally agree with this sentiment. I'd be happy to reopen if we can pin down an actionable step. (Bearing in mind Django 3.0 is Python 3.6+ only.)

I'm initially doubtful that a workaround for an obtuse Python bug is going to be worth our effort... — as you say, who knows?

(I'm pretty sure I used to have to restart the dev server quite frequently back in the day... — not that that's an argument for anything I suppose.)

[Keryn Knight]

Yeah, if I had any real idea about how to move it forwards, I fully appreciate that would help :)

My main concern is twofold:

• New users are potentially (though not necessarily) more likely to experience a problem if it is a version specific issue, as they may not have the skills or opportunity to be on the latest and greatest Python version; or if they do encounter it (regardless of version) it is masking an actual error.
• that 2.2 is an LTS, and 3.5 is still one of the supported versions for that, so even if there's a perceived ergonomics regression in something as vital as autoreloading (being that wsgi is long-lived but not statically typed), the opportunity to fix it before it's essentially is frozen is arguably perhaps up to December, after which it'd almost certainly be a sub-par experience for those sticking with it (and the fewer users therein who encounter the problem) for the remainder of it's lifetime (until the next LTS in 2022)

Once upon a time, at least SyntaxError caused a restart to be required IIRC, but I think that's not been the case for a while now (I'd check further, but I can't recall when it might've been). I can't recall if NameError or UnboundLocalError previously caused similar manual restarts, but I wouldn't be entirely surprised.

[Keryn Knight]

Adding details as I figure them out a bit, on the off-chance they prove valuable:

instrumented django/urls/resolvers.py:

def url_patterns(...):
    patterns = getattr(self.urlconf_module, "urlpatterns", self.urlconf_module)
    print('url_patterns', type(patterns), patterns)

instrumented django/utils/autoreload.py:

def run(...):
    [...]
    try:
        v = get_resolver().urlconf_module
        print('run', type(v), v)
    [...]

Then, running the utime(...) script in a while loop as above, with runserver running (and a commented out):

url_patterns <class 'list'> [<URLResolver <module 't30500.urls2' from '/path/to/t30500/t30500/urls2.py'> (None:None) ''>]
run <class 'module'> <module 't30500.urls' from '/path/to/t30500/t30500/urls.py'>
url_patterns <class 'list'> [<URLPattern ''>]

The order of those calls changes sometimes (for me), so I guess it's maybe separate threads and non-deterministic? But importantly, they stay the same types and values, by the look of it.

If a is uncommented, to raise NameError: name 'a' is not defined, every time NameError is thrown, the only print is:

run <class 'module'> <module 't30500.urls' from '/path/to/t30500/t30500/urls.py'>
Exception in thread django-main-thread: [...]

when ImproperlyConfigured: The included URLconf 't30500.urls' ... is thrown, the only print is instead, this:

url_patterns <class 'module'> <module 't30500.urls' from '/path/to/t30500/t30500/urls.py'>
Exception in thread django-main-thread: [...]

This seems like an important distinction (to me, with my highly sophisticated print-debugging, as pdb was being little help), and additionally the patterns variable is a module, rather than a list.

[Peter J. Farrell]

Just to follow up from the request on our duplicate ticket #30674, the version of Python we were running is Python 3.5.2 (default, Nov 12 2018, 13:43:14) [GCC 5.4.0 20160609] on linux. We can't update to the latest 3.5.7 as it's not available in the OS repository (APT / Yum) and we are not allowed to install from source.

[Tom Forbes]

I've spent some time digging into this, and it is indeed a race condition of some kind. I think it comes down to this CPython issue: ​https://bugs.python.org/issue36284 (importlib.import_module() not thread safe if Exception is raised (3.4, 3.5)). I've re-opened the ticket and marked it against master, because it's not clear when or even if this is fixed in Python core.

Basically, as far as I can tell, the code inside the autoreloader that prevents one race condition causes another. Here it's racing the 'run_checks' method called from runserver's 'inner_run', which both load the urlconf_module via the 'urlconf_module' cached property. In the case of an error being thrown _and a race happening_, then the module returned is not initialized correctly and has no 'urlpatterns' attribute. This causes the "patterns = getattr(self.urlconf_module, "urlpatterns", self.urlconf_module)" statement to fall back to the default, which is the module object itself. This then fails the iteration.

The obvious thing to do here is to add a lock around 'urlconf_module', or in the ticket linked above you can call importlib.reload() on the result. I'd have a preference for the lock approach on all Python versions, and after adding one I've not seen any failures after running the reproduction script for half an hour.

[Tom Forbes]

PR: ​https://github.com/django/django/pull/11714

[Claude Paroz]

Is it really worth adding this to master, if the bug cannot be reproduced with Python 3.6+?

[Tom Forbes]

It was apparently fixed in 3.6.3 via this ticket: ​https://bugs.python.org/issue31070 - "Fix a race condition in importlib _get_module_lock()." and in this MR: ​https://github.com/python/cpython/pull/3033/files

I'd like to fix it in master for a couple of reasons:

1. It adds no overhead at all and ensures this won't happen if there is a regression in upstream Python. What if future importlib changes cause this, or something similar to flair up again? - Note that the bug was only _noticed_ due to some test changes, this doesn't give me a lot of hope.

2. The only source of contention while starting the autoreloader is importing the urlconf module, relying on unspecified, and until recently buggy, thread safety in importlib isn't great. I'd like to be explicit here.

But, then again, this specific issue is fixed in 3.6.3+, so maybe it's not worth it.

[Claude Paroz]

First of all, I'd like to thank you so much for the amazing research you've done on that issue!

Now saying it's not adding overhead is not completely true, however it's a minimal overhead (creating lock, entering context manager, ...). And what about the other occurrences of import_module in Django code? I think that at some point we have to trust Python for not regressing in that function. So I still think this should be fixed in Django 2.2 but not in master.

[Mariusz Felisiak]

Tom, thanks for the research. I agree with Claude let's fix this only in Django 2.2, we officially support only the latest point release of each Python series.

[Tom Forbes]

Ok, makes sense. Updated PR against 2.2.x: ​https://github.com/django/django/pull/11717

[Mariusz Felisiak <felisiak.mariusz@…>]

In 6402855:

[2.2.x] Fixed #30500 -- Fixed race condition in loading URLconf module.