#29186: "django.request" logging breaks "logging.handlers.SocketHandler"
------------------------------+-----------------------------------------
Reporter: direx | Owner: HyunTae Hwang
Type: Bug | Status: assigned
Component: Core (Other) | Version: 2.0
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
------------------------------+-----------------------------------------
Old description:
> When setting up logging with Python's default `SocketHandler` then the
> log messages produced by `django.request` cause an exception in the
> logging system. This happens everywhere where Django passes an
> `extra={'request': request}` dictionary to log messages. The reason for
> this is that the request object cannot be pickled.
>
> Steps to reproduce (example):
>
> 1. `./manage.py startproject`
> 1. Add this logging config in settings:
> {{{
> LOGGING = {
> 'version': 1,
> 'disable_existing_loggers': False,
> 'handlers': {
> 'socket_handler': {
> 'class': 'logging.handlers.SocketHandler',
> 'host': '127.0.0.1',
> 'port': 9020,
> }
> },
> 'loggers': {
> 'django.request': {
> 'handlers': ['socket_handler'],
> 'level': 'INFO',
> 'propagate': False,
> },
> }
> }
> }}}
> 1. `./manage.py migrate`
> 1. `./manage.py runserver`
> 1. `wget http://127.0.0.1:8000/invalid -O /dev//null`
>
> The exception is this one:
>
> {{{
> --- Logging error ---
> Traceback (most recent call last):
> File "/usr/lib/python3.6/logging/handlers.py", line 633, in emit
> s = self.makePickle(record)
> File "/usr/lib/python3.6/logging/handlers.py", line 605, in makePickle
> s = pickle.dumps(d, 1)
> File "/usr/lib/python3.6/copyreg.py", line 65, in _reduce_ex
> raise TypeError("can't pickle %s objects" % base.__name__)
> TypeError: can't pickle BufferedReader objects
> Call stack:
> File "/usr/lib/python3.6/threading.py", line 884, in _bootstrap
> self._bootstrap_inner()
> File "/usr/lib/python3.6/threading.py", line 916, in _bootstrap_inner
> self.run()
> File "/usr/lib/python3.6/threading.py", line 864, in run
> self._target(*self._args, **self._kwargs)
> File "/usr/lib/python3.6/socketserver.py", line 639, in
> process_request_thread
> self.finish_request(request, client_address)
> File "/usr/lib/python3.6/socketserver.py", line 361, in finish_request
> self.RequestHandlerClass(request, client_address, self)
> File "/usr/lib/python3.6/socketserver.py", line 696, in __init__
> self.handle()
> File "/home/direx/virtualenv/django-2.0/lib/python3.6/site-
> packages/django/core/servers/basehttp.py", line 154, in handle
> handler.run(self.server.get_app())
> File "/usr/lib/python3.6/wsgiref/handlers.py", line 137, in run
> self.result = application(self.environ, self.start_response)
> File "/home/direx/virtualenv/django-2.0/lib/python3.6/site-
> packages/django/contrib/staticfiles/handlers.py", line 66, in __call__
> return self.application(environ, start_response)
> File "/home/direx/virtualenv/django-2.0/lib/python3.6/site-
> packages/django/core/handlers/wsgi.py", line 146, in __call__
> response = self.get_response(request)
> File "/home/direx/virtualenv/django-2.0/lib/python3.6/site-
> packages/django/core/handlers/base.py", line 93, in get_response
> extra={'status_code': 404, 'request': request},
> Message: 'Not Found: %s'
> Arguments: ('/invalid',)
> }}}
>
> Of course these steps are only an example. This bug does not only apply
> to 404 errors, but also to CSRF verfication errors for instance. In fact
> all places where the `request` object is passed in as an `extra` logger
> argument.
>
> I see a few possible solutions for this issue:
>
> 1. Remove the `request` object from the `extra` log message dict. Right
> now I am not even sure why this is required.
> 1. Make the entire `request` object pickleable (probably not an easy
> task)
> 1. Pass in a reduced (pickable) version of the request object in the
> `extra` dict
> 1. Ship a compatible version of `SocketHandler`
>
> BTW: socket logging is explicitly mentioned in the Django docs:
>
> > The handler is the engine that determines what happens to each message
> in a logger. It describes a particular logging behavior, such as writing
> a message to the screen, to a file, **or to a network socket**.
>
> This bug also applies to older Django versions.
New description:
Just wondering what the status of this is. I get occasional errors like
the following in my log file. Looks like it's this same issue. I'm
running Django 3.1.8.
{{{
--- Logging error ---
Traceback (most recent call last):
File "/data/project/spi-tools-dev/python-
distros/Python-3.7.3-install/lib/python3.7/logging/handlers.py", line 630,
in emit
s = self.makePickle(record)
File "/data/project/spi-tools-dev/python-
distros/Python-3.7.3-install/lib/python3.7/logging/handlers.py", line 602,
in makePickle
s = pickle.dumps(d, 1)
File "/data/project/spi-tools-dev/python-
distros/Python-3.7.3-install/lib/python3.7/copyreg.py", line 65, in
_reduce_ex
raise TypeError("can't pickle %s objects" % base.__name__)
TypeError: can't pickle _Input objects
Call stack:
File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-
packages/django/core/handlers/wsgi.py", line 133, in __call__
response = self.get_response(request)
File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-
packages/django/core/handlers/base.py", line 136, in get_response
request=request,
File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-
packages/django/utils/log.py", line 230, in log_response
exc_info=exc_info,
}}}
--
Comment (by Roy Smith):
Just wondering what the status of this is. I get occasional errors like
the following in my log file. Looks like it's this same issue. I'm
running Django 3.1.8.
{{{
--- Logging error ---
Traceback (most recent call last):
File "/data/project/spi-tools-dev/python-
distros/Python-3.7.3-install/lib/python3.7/logging/handlers.py", line 630,
in emit
s = self.makePickle(record)
File "/data/project/spi-tools-dev/python-
distros/Python-3.7.3-install/lib/python3.7/logging/handlers.py", line 602,
in makePickle
s = pickle.dumps(d, 1)
File "/data/project/spi-tools-dev/python-
distros/Python-3.7.3-install/lib/python3.7/copyreg.py", line 65, in
_reduce_ex
raise TypeError("can't pickle %s objects" % base.__name__)
TypeError: can't pickle _Input objects
Call stack:
File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-
packages/django/core/handlers/wsgi.py", line 133, in __call__
response = self.get_response(request)
File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-
packages/django/core/handlers/base.py", line 136, in get_response
request=request,
File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-
packages/django/utils/log.py", line 230, in log_response
exc_info=exc_info,
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/29186#comment:6>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
--
You received this message because you are subscribed to the Google Groups
"Django updates" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To view this discussion on the web visit
https://groups.google.com/d/msgid/django-updates/063.b8823bdaf1a7fb9d0246ddc19ce315f6%40djangoproject.com.
