'WebRequest' object has no attribute 'client_addr'

[marcinocto]

Hi, I've recently migrated my Django project from WSGI + gunicorn to ASGI + daphne. It's working great apart from an occasional error in my Sentry/logs builtins.AttributeError: 'WebRequest' object has no attribute 'client_addr'.
It just seems to be the problem in the log.debug call on connectionLost in https://github.com/django/daphne/blob/main/daphne/http_protocol.py#L213
Looking at the class it seems that there is a chance that the client_addr is not set until later in the process method https://github.com/django/daphne/blob/main/daphne/http_protocol.py#L81 so there's a chance that the self.client_addr is simply not set.

I can't replicate this error by any means, it happens only occasionally (I guess that's why it pops up in the connectionLost method). Should the client_addr be set to None by default so that this log message doesn't cause fatals?

BTW I've seen #304 and #244. First one is giving 404 on SO, second one seems similar but they're mentioning websockets whereas I haven't even got to the point where I'm supporting websockets in my app.

• Your OS and runtime environment, and browser if applicable
  Presumably platform browser agnostic. I don't have a reproduction method.

• A pip freeze output showing your package versions

channels==3.0.3
channels_redis==3.3.0
daphne==3.0.2
Django==3.2.6

• How you're running Channels (runserver? daphne/runworker? Nginx/Apache in front?)

daphne on Heroku with daphne my_app.asgi:application --port $PORT --bind 0.0.0.0 --verbosity 2 in Procfile

• Console logs and full tracebacks of any errors

 Jan 28 11:55:38 app/web.3 Unhandled Error
 Jan 28 11:55:38 app/web.3 Traceback (most recent call last):
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/internet/asyncioreactor.py", line 257, in run
 Jan 28 11:55:38 app/web.3     self._asyncioEventloop.run_forever()
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/asyncio/base_events.py", line 570, in run_forever
 Jan 28 11:55:38 app/web.3     self._run_once()
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/asyncio/base_events.py", line 1859, in _run_once
 Jan 28 11:55:38 app/web.3     handle._run()
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/asyncio/events.py", line 81, in _run
 Jan 28 11:55:38 app/web.3     self._context.run(self._callback, *self._args)
 Jan 28 11:55:38 app/web.3 --- <exception caught here> ---
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/python/log.py", line 101, in callWithLogger
 Jan 28 11:55:38 app/web.3     return callWithContext({"system": lp}, func, *args, **kw)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/python/log.py", line 85, in callWithContext
 Jan 28 11:55:38 app/web.3     return context.call({ILogContext: newCtx}, func, *args, **kw)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/python/context.py", line 118, in callWithContext
 Jan 28 11:55:38 app/web.3     return self.currentContext().callWithContext(ctx, func, *args, **kw)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/python/context.py", line 83, in callWithContext
 Jan 28 11:55:38 app/web.3     return func(*args, **kw)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/internet/asyncioreactor.py", line 145, in _readOrWrite
 Jan 28 11:55:38 app/web.3     self._disconnectSelectable(selectable, why, read)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/internet/posixbase.py", line 300, in _disconnectSelectable
 Jan 28 11:55:38 app/web.3     selectable.readConnectionLost(f)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/internet/tcp.py", line 308, in readConnectionLost
 Jan 28 11:55:38 app/web.3     self.connectionLost(reason)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/internet/tcp.py", line 325, in connectionLost
 Jan 28 11:55:38 app/web.3     protocol.connectionLost(reason)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/twisted/web/http.py", line 2508, in connectionLost
 Jan 28 11:55:38 app/web.3     request.connectionLost(reason)
 Jan 28 11:55:38 app/web.3   File "/app/.heroku/python/lib/python3.8/site-packages/daphne/http_protocol.py", line 213, in connectionLost
 Jan 28 11:55:38 app/web.3     logger.debug("HTTP disconnect for %s", self.client_addr)
 Jan 28 11:55:38 app/web.3 builtins.AttributeError: 'WebRequest' object has no attribute 'client_addr'

[carltongibson]

Hi @marcinocto — Yes... interesting. Happy to take a fix here.

... I can't replicate this error by any means ...

It would be good to pin that down. 🤔

[marcinocto]

Our backend app is used by mobile clients and because it happens on connectionLost then perhaps it happens when e.g. a mobile client drops connection mid-request? Trying to replicate such behaviour might be tricky.
I think fixing that potential attribute not set wouldn't do any harm to the code anyway, even doing a getattr(self, 'client_addr', None) would do :)

[marcinocto]

Happy to submit a PR if such "fix" would be acceptable

[carltongibson]

@marcinocto — Yes, it seems reasonable.

• Removing the else clause in process should be available.
• Just a regression test making sure the attribute is None on a fresh instance would be good.