Channels: Django 3 + channels - runserver does not work with autoreload

[swist]

I am trying to set up an example repo for Django 3 + ariadne + channels.

I have added channels and ariadne to the top of INSTALLED_APPS

ASGI_APPLICATION = "server.routing.application"
INSTALLED_APPS = [
    "channels",
    "django.contrib.admin",
    "django.contrib.auth",
    "django.contrib.contenttypes",
    "django.contrib.sessions",
    "django.contrib.messages",
    "django.contrib.staticfiles",
    "ariadne.contrib.django",
]

And set up routing.py:

from typing import Callable
from ariadne.asgi import GraphQL
from channels.routing import URLRouter, ProtocolTypeRouter
from django.core.handlers.asgi import ASGIHandler
from django.urls import path, re_path

from gql.schema import schema


# This is an ASGI2 compatibility class so that we can use ariadne
# subscriptions with channels.
# Once channels supports ASGI3 this class can go away:
# https://github.com/mirumee/ariadne/issues/210
class DjangoChannelsGraphQL(GraphQL):
    def __call__(self, scope) -> Callable:
        async def handle(receive, send):
            await super(DjangoChannelsGraphQL, self).__call__(scope, receive, send)

        return handle


application = ProtocolTypeRouter(
    {
        "websocket": URLRouter(
            [path("graphql/", DjangoChannelsGraphQL(schema, debug=True))]
        ),
        "http": URLRouter(
            [
                path("graphql/", DjangoChannelsGraphQL(schema, debug=True)),
                re_path(r"", ASGIHandler),
            ]
        ),
    }
)

When I run python manage.py runserver

I get hit with django.core.exceptions.SynchronousOnlyOperation: You cannot call this from an async context - use a thread or sync_to_async.

I don't quite understand channels' runserver config, but I'll include trace for a good measuer:
```
November 02, 2019 - 16:48:08
Django version 3.0b1, using settings 'server.settings'
Starting ASGI/Channels version 2.3.1 development server at http://127.0.0.1:8000/
Quit the server with CONTROL-C.
/Users/swistak/messenger/.venv/lib/python3.7/site-packages/channels/management/commands/runserver.py changed, reloading.
Traceback (most recent call last):
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/core/management/base.py", line 328, in run_from_argv
self.execute(args, cmd_options)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/core/management/commands/runserver.py", line 60, in execute
super().execute(args, *options)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/core/management/base.py", line 369, in execute
output = self.handle(args, *options)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/channels/management/commands/runserver.py", line 59, in handle
super().handle(args, *options)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/core/management/commands/runserver.py", line 95, in handle
self.run(options)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/core/management/commands/runserver.py", line 102, in run
autoreload.run_with_reloader(self.inner_run, *options)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/utils/autoreload.py", line 599, in run_with_reloader
start_django(reloader, main_func, args, *kwargs)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/utils/autoreload.py", line 584, in start_django
reloader.run(django_main_thread)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/utils/autoreload.py", line 299, in run
self.run_loop()
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/utils/autoreload.py", line 305, in run_loop
next(ticker)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/utils/autoreload.py", line 353, in tick
self.notify_file_changed(filepath)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/utils/autoreload.py", line 328, in notify_file_changed
trigger_reload(path)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/utils/autoreload.py", line 223, in trigger_reload
sys.exit(3)
SystemExit: 3

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "manage.py", line 21, in
main()
File "manage.py", line 17, in main
execute_from_command_line(sys.argv)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/core/management/__init__.py", line 401, in execute_from_command_line
utility.execute()
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/core/management/__init__.py", line 395, in execute
self.fetch_command(subcommand).run_from_argv(self.argv)
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/core/management/base.py", line 341, in run_from_argv
connections.close_all()
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/db/utils.py", line 230, in close_all
connection.close()
File "/Users/swistak/messenger/.venv/lib/python3.7/site-packages/django/utils/asyncio.py", line 22, in inner
raise SynchronousOnlyOperation(message)
django.core.exceptions.SynchronousOnlyOperation: You cannot call this from an async context - use a thread or sync_to_async.```

[maxmalysh]

Same for me. Autoreload triggers the following exception:

/Users/mmalysh/Development/my-website/myproject/apps/landing/views.py changed, reloading.
Traceback (most recent call last):
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/core/management/base.py", line 328, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/core/management/commands/runserver.py", line 60, in execute
    super().execute(*args, **options)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/core/management/base.py", line 369, in execute
    output = self.handle(*args, **options)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/channels/management/commands/runserver.py", line 59, in handle
    super().handle(*args, **options)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/core/management/commands/runserver.py", line 95, in handle
    self.run(**options)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/core/management/commands/runserver.py", line 102, in run
    autoreload.run_with_reloader(self.inner_run, **options)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/utils/autoreload.py", line 599, in run_with_reloader
    start_django(reloader, main_func, *args, **kwargs)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/utils/autoreload.py", line 584, in start_django
    reloader.run(django_main_thread)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/utils/autoreload.py", line 299, in run
    self.run_loop()
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/utils/autoreload.py", line 305, in run_loop
    next(ticker)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/utils/autoreload.py", line 353, in tick
    self.notify_file_changed(filepath)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/utils/autoreload.py", line 328, in notify_file_changed
    trigger_reload(path)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/utils/autoreload.py", line 223, in trigger_reload
    sys.exit(3)
SystemExit: 3

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Users/mmalysh/Development/my-website/myproject/manage.py", line 22, in <module>
    execute_from_command_line(sys.argv)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/core/management/__init__.py", line 401, in execute_from_command_line
    utility.execute()
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/core/management/__init__.py", line 395, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/core/management/base.py", line 341, in run_from_argv
    connections.close_all()
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/db/utils.py", line 230, in close_all
    connection.close()
  File "/Users/mmalysh/Development/my-website/venv/lib/python3.6/site-packages/django/utils/asyncio.py", line 22, in inner
    raise SynchronousOnlyOperation(message)
django.core.exceptions.SynchronousOnlyOperation: You cannot call this from an async context - use a thread or sync_to_async.

My asgi.py:

import os
from django.core.asgi import get_asgi_application

os.environ.setdefault("DJANGO_SETTINGS_MODULE", "config.settings")
application = get_asgi_application()

Dependencies:

Django==3.0.0
channels==2.3.1

[carltongibson]

Thanks for the report.

@andrewgodwin Pinging you on this on, since it's _new_: I didn't get a chance to look into it yet but, your first thought: do we need an adjustment to the runserver command here, or is this something to push back to Django? (Ta!)

[andrewgodwin]

Oh, this is very interesting indeed. It's probably Channels' job to handle, as it's the one making the outside context asynchronous, but I can't be totally sure, given there's only one channels file in the entire traceback. I suspect the runserver command Channels ships isn't quite async-safe enough, and the new async-safety checks in Django are catching that.

Sadly, we can't use the DJANGO_ALLOW_ASYNC_UNSAFE workaround until 3.0.1 ships, either.

[carltongibson]

Hi @andrewgodwin. I'm going to have to get you to give me an asyncio debugging lesson but... 🙂

I'm not 100% convinced that, when this error come up, we're in an async context.

• It comes up in BaseCommand.run_from_argv(), when we're handling the SystemExit thrown by the autoreloader.

As you know, django.utils.asyncio.async_unsafe() calls asyncio.get_event_loop(), and if it's running raises our exception.

But the only loop in play is that from the Twisted reactor, which we (channels) start in our inner_run().

Could that be the loop that's getting returned? (How do I check that?) (It's running so, if it were...)

But, we're not ourselves running _inside_ of that event loop at the point where the exception is raised.
(So could it be that the check in async_unsafe() isn't strict enough?)

Update: Twisted is making the exact same get_event_loop() call that async_unsafe is when we instantiate the AsyncioReactor, which we do from daphne.server

[andrewgodwin]

I'm going to replicate this locally and just debug it, I think, I'm really not sure what's going on here.

[andrewgodwin]

It looks like raising SystemExit plunges out of twisted without it closing out the asyncio event loop, meaning that any code running "on exit" triggers async-unsafety. I've opened https://github.com/django/channels/pull/1391 to detect this and manually stop the event loop in this situation.

[carltongibson]

I'm looking at this again now.

There are two threads in play. The "async" thread, running Daphne, and the "autoreloader" thread, which raises the SystemExit.

We're in the "autoreloader" thread when we hit the issue, the "async" thread is blocked at Daphne's run() call, which ultimately calls run_forever() on the event loop, but get_event_loop must be returning the same event loop (the global policy default) from both threads. (I think)

I'm trying to rewrite it without the rest of Django in play 🙂

[andrewgodwin]

Yeah, there's something wonky with the rest of the threads and SystemExit, which is why I wanted to write a working fix for the symptom (in that PR) while maybe eventually working out the underlying cause.

It may also be Twisted's reactor at play here specifically, since I believe the Twisted reactor is across all threads, and so that might be causing it to span them?

[carltongibson]

That makes a bit of sense. Before threading, at import we call asyncioreactor.install(), which sets the default loop, from the main thread, on the reactor.

(In contrast, I'm spinning up a thread and seeing There is no current event loop in thread 'async-thread'. which means I'll need to pass in the event loop in order to replicate what's going on.)

Current status 🤔

[carltongibson]

OK, more or less, this is what I think is going on:

import asyncio
import threading
import time

from django.utils.asyncio import async_unsafe, SynchronousOnlyOperation


@async_unsafe("Boom! 💥")
def sync_only():
    print("sync_only successfully called.")


async def this_should_blow_up():
    print("About to call sync_only from async context")

    try:
        sync_only()
    except SynchronousOnlyOperation as e:
        print("Correctly raised SynchronousOnlyOperation")


def run_in_async_thread(loop):
    print("Async thread starting")

    #loop = asyncio.get_event_loop()
    asyncio.set_event_loop(loop)

    loop.create_task(this_should_blow_up())

    print("Will start the loop")
    loop.run_forever()

    print("Never get here: Async thread finished")



if __name__ == '__main__':
    async_thread = threading.Thread(
        target=run_in_async_thread, args=(asyncio.get_event_loop(),), kwargs={}, name='async-thread'
    )
    async_thread.daemon = True # not sure this is necessary, but autoloader does it to Django. 
    async_thread.start()

    time.sleep(0.5)

    print("About to call sync_only from SYNC context")
    try:
        sync_only()
    except SynchronousOnlyOperation as e:
        print("INCORRECTLY raised SynchronousOnlyOperation")
        print("   This SHOULD be fine")

Output when run:

(django) ~/Desktop $ python asyncio_example.py 
Async thread starting
Will start the loop
About to call sync_only from async context
Correctly raised SynchronousOnlyOperation
About to call sync_only from SYNC context
INCORRECTLY raised SynchronousOnlyOperation
   This SHOULD be fine

[carltongibson]

Hi @swist @maxmalysh Would either or both of you be able to give the PR here a run https://github.com/django/daphne/pull/294? It should do the business, but it would be good to have a confirmation.

[carltongibson]

My little test script above, adjusted to pass a new event loop (and expect that) works well too:

Output fragment:

About to call sync_only from SYNC context
sync_only successfully called.
Yay! The right result. 💃

[maxmalysh]

Looks OK. Thanks for the fix!

Dependencies:

$ python --version
Python 3.6.9
$ pip install django==3.0.1
$ pip install git+https://github.com/django/daphne.git@refs/pull/294/merge
$ pip install channels==2.3.1
$ pip install Twisted==19.7.0

Log:

$ python manage.py runserver 8123
Watching for file changes with StatReloader
Performing system checks...

System check identified no issues (0 silenced).
December 18, 2019 - 19:43:51
Django version 3.0.1, using settings 'config.settings'
Starting ASGI/Channels version 2.3.1 development server at http://127.0.0.1:8123/
Quit the server with CONTROL-C.
/Users/mmalysh/Development/project/src/apps/api/views.py changed, reloading.
Watching for file changes with StatReloader
Performing system checks...

System check identified no issues (0 silenced).
December 18, 2019 - 19:44:01
Django version 3.0.1, using settings 'config.settings'
Starting ASGI/Channels version 2.3.1 development server at http://127.0.0.1:8123/
Quit the server with CONTROL-C.

[carltongibson]

Super. Thanks for taking the time to confirm @maxmalysh. I shall merge and tag now. 👍

[carltongibson]

Updating Daphne to 2.4.1 should see you good to go.

Thanks all.