WARNING daphne.server ASGIStaticFilesHandler WebRequest took too long to shut down and was killed

[itayAmza]

Might be related to this I've started getting those errors out of the blue every few graphql queries, while the server freezes completely and stays unresponsive until I restart.

2024-04-29 17:57:33,887 DEBUG [daphne.http_protocol:261] http_protocol 1 281473823117408 HTTP 200 response started for ['172.22.0.1', 33126]
2024-04-29 17:57:33,889 DEBUG [daphne.http_protocol:229] http_protocol 1 281473823117408 HTTP close for ['172.22.0.1', 33126]
2024-04-29 17:57:33,890 DEBUG [daphne.http_protocol:275] http_protocol 1 281473823117408 HTTP response complete for ['172.22.0.1', 33126]
2024-04-29 17:57:33,890 INFO [django.channels.server:168] runserver 1 281473823117408 HTTP POST /graphql 200 [5.55, 172.22.0.1:33126]
2024-04-29 17:57:43,729 DEBUG [daphne.http_protocol:219] http_protocol 1 281473823117408 HTTP disconnect for ['172.22.0.1', 54880]
2024-04-29 17:57:54,242 WARNING [daphne.server:278] server 1 281473823117408 Application instance <Task pending name='Task-38' coro=<ASGIStaticFilesHandler.__call__() running at /env/lib/python3.12/site-packages/django/contrib/staticfiles/handlers.py:101> wait_for=<Task cancelling name='Task-43' coro=<ASGIHandler.handle.<locals>.process_request() running at /env/lib/python3.12/site-packages/django/core/handlers/asgi.py:193> wait_for=<Future pending cb=[_chain_future.<locals>._call_check_cancel() at /usr/local/lib/python3.12/asyncio/futures.py:387, Task.task_wakeup()]> cb=[Task.task_wakeup()]>> for connection <WebRequest at 0xffffb36689e0 method=POST uri=/graphql clientproto=HTTP/1.1> took too long to shut down and was killed.
2024-04-29 17:57:55,246 WARNING [daphne.server:278] server 1 281473823117408 Application instance <Task cancelling name='Task-38' coro=<ASGIStaticFilesHandler.__call__() running at /env/lib/python3.12/site-packages/django/contrib/staticfiles/handlers.py:101> wait_for=<_GatheringFuture pending cb=[Task.task_wakeup()]>> for connection <WebRequest at 0xffffb36689e0 method=POST uri=/graphql clientproto=HTTP/1.1> took too long to shut down and was killed.

Debug logs makes me think that the server is experiencing issues when attempting to close down tasks after processing requests. It started few days ago without any change on my side and it happens all the time now. There is no particular query who causes this, its just happens after few api calls, even if I just pick some random query and call it few times from Postman. I don't experience those issues on prod, which using different environment, only on my dev server which I'm running on local host, using docker desktop.

I've tried updating packages to most updated versions, but nothing changed. My requirements file

Django==5.0.4
graphene==3.3.0
graphene_django==3.2.0
django-graphql-jwt==0.4.0
graphene_graphiql_explorer==0.1.1
python-dotenv==1.0.1
django-utils-six==2.0.0
django-composite-field==2.0.0
channels==4.1.0
channels-redis==4.1.0
daphne==4.1.2
pymemcache==4.0.0
psycopg2==2.9.9
debugpy==1.8.1
django-push-notifications==3.0.2
aioapns==3.1
celery==5.4.0

My dev docker compose file

version: '3'

services:
  django:
    build: .
    command: ["sh", "-c", "python -m debugpy --listen 0.0.0.0:5678 manage.py runserver 0.0.0.0:8000 --nothreading --noreload"]
    ports:
      - "8000:8000"
      - "5678:5678"
    restart: unless-stopped
    env_file:
      - .env

  redis:
    image: redis:latest
    ports:
      - "6379:6379"

  memcached:
    image: memcached:latest
    ports:
      - "11211:11211"

  celery:
    build: .
    command: ["sh", "-c", "celery -A expertly_server worker --loglevel=info"]
    depends_on:
      - django
      - redis

My prod docker compose file

version: '3'

services:
  django:
    build: .
    command: >
      sh -c "python manage.py collectstatic --no-input &&
      daphne expertly_server.asgi:application --bind 0.0.0.0 --port 8000"
    env_file:
      - /home/environment/.env
    volumes:
      - static_volume:/static
    expose:
      - 8000

  certbot:
    image: certbot/certbot
    volumes:
      - certbot_etc:/etc/letsencrypt
      - certbot_var:/var/lib/letsencrypt
      - ./data/certbot:/var/www/certbot
    entrypoint: "/bin/sh -c 'trap exit TERM; while :; do certbot renew; sleep 12h & wait $${!}; done'"

  nginx:
    build:
      context: .
      dockerfile: nginx/Dockerfile.nginx
    volumes:
      - static_volume:/static
      - ./data/certbot:/var/www/certbot
      - certbot_etc:/etc/letsencrypt
      - certbot_var:/var/lib/letsencrypt
    ports:
      - 80:80
      - 443:443
    depends_on:
      - django

  redis:
    image: redis:latest
    expose:
      - 6379

  memcached:
    image: memcached:latest
    expose:
      - 11211

  celery:
    build: .
    command: ["sh", "-c", "celery -A expertly_server worker --loglevel=info"]
    depends_on:
      - django
      - redis

volumes:
  static_volume:
    name: static_volume
  certbot_etc:
    name: certbot_etc
  certbot_var:
    name: certbot_var

python version is 3.11 When it happens there is no notable spike in CPU or memory usage on the docker container. I guess the errors are just the symptoms of the timeouts caused by the server unresponsiveness but I don't know even where I can even start debugging this issue.

[syifarahmat]

Same With My Case

[Evan-Vamprine]

Same

[fabiodeabreuaraujo]

Me too

[carltongibson]

I'm going to lock this conversation as all the "Me too" comment are just noise.

ASGIStaticFilesHandler is only used in development, and this is a artefact of the development server reloading. If someone wants to look at making ASGIStaticFilesHandler exit cleanly in that case, PRs are welcome.

[carltongibson]

I'm going to treat this as a duplicate of #1119.