A PicklingError occurs when using Django channels together with a logging SocketHandler, if an HTTP error status is returned.

[Vinay Sajip]

Assume that the logging configuration includes a logging.handlers.SocketHandler. When a view returns an HTTP error status such as 400, the behavior is different according to whether or not channels are in use. When channels are not in use, you get this printed on the console:

Bad Request: /fail/400
[13/Jan/2025 21:39:04] "GET /fail/400 HTTP/1.1" 400 26314

Well and good. However, if channels are in use, you get this:

Bad Request: /fail/400
--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.10/logging/handlers.py", line 677, in emit
    s = self.makePickle(record)
  File "/usr/lib/python3.10/logging/handlers.py", line 649, in makePickle
    s = pickle.dumps(d, 1)
  File "/home/vinay/.local/share/virtualenvs/django-base/lib/python3.10/site-packages/django/urls/resolvers.py", line 105, in __reduce_ex__
    raise PicklingError(f"Cannot pickle {self.__class__.__qualname__}.")
_pickle.PicklingError: Cannot pickle ResolverMatch.
Call stack:
  File "/usr/lib/python3.10/threading.py", line 973, in _bootstrap
    self._bootstrap_inner()
  File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.10/threading.py", line 953, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/lib/python3.10/concurrent/futures/thread.py", line 83, in _worker
    work_item.run()
  File "/usr/lib/python3.10/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/home/vinay/.local/share/virtualenvs/django-base/lib/python3.10/site-packages/asgiref/sync.py", line 522, in thread_handler
    return func(*args, **kwargs)
  File "/home/vinay/.local/share/virtualenvs/django-base/lib/python3.10/site-packages/django/utils/log.py", line 248, in log_response
    getattr(logger, level)(
Message: '%s: %s'
Arguments: ('Bad Request', '/fail/400')
HTTP GET /fail/400 400 [0.24, 127.0.0.1:49610]

The reason appears to be due to this code in django.utils.log.py, in function log_response:

    getattr(logger, level)(
        message,
        *args,
        extra={
            "status_code": response.status_code,
            "request": request,
        },
        exc_info=exception,
    )

The difference between the channels case and the other is that in the channels case, the extra dictionary contains the request key points to an instance of django.core.handlers.asgi.ASGIRequest, whereas in the non-channels case the request key points to an instance of django.core.handlers.wsgi.WSGIRequest. In the WSGI request handling path, the resolver_match attribute of the request is not changed after being initialized to None, whereas in the ASGI request handling path, the resolver_match attribute is set to a ResolverMatch instance, which is not pickleable, and leads to the above traceback.

Furthermore, when looking at this problem, the ASGIRequest.__init__ sets the resolver_match attribute to None twice. Either one of those is redundant, or a comment is needed to say why the two set statements are present.