Opened 7 years ago
Last modified 21 months ago
#29186 new Bug
"django.request" logging breaks "logging.handlers.SocketHandler" — at Initial Version
Reported by: | direx | Owned by: | nobody |
---|---|---|---|
Component: | Core (Other) | Version: | 2.0 |
Severity: | Normal | Keywords: | |
Cc: | Anvesh Mishra | Triage Stage: | Accepted |
Has patch: | no | Needs documentation: | no |
Needs tests: | no | Patch needs improvement: | no |
Easy pickings: | no | UI/UX: | no |
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):
./manage.py startproject
- 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, }, } }
./manage.py migrate
./manage.py runserver
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:
- Remove the
request
object from theextra
log message dict. Right now I am not even sure why this is required. - Make the entire
request
object pickleable (probably not an easy task) - Pass in a reduced (pickable) version of the request object in the
extra
dict - 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.