Changes between Initial Version and Version 6 of Ticket #29186


Ignore:
Timestamp:
Jun 4, 2021, 11:16:17 AM (3 years ago)
Author:
Roy Smith
Comment:

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,

Legend:

Unmodified
Added
Removed
Modified
  • Ticket #29186

    • Property Component UncategorizedCore (Other)
    • Property Triage Stage UnreviewedAccepted
    • Property Owner changed from nobody to HyunTae Hwang
    • Property Status newassigned
    • Property Has patch set
    • Property Patch needs improvement set
  • Ticket #29186 – Description

    initial v6  
    1 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.
     1Just 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.
    22
    3 Steps to reproduce (example):
    4 
    5 1. `./manage.py startproject`
    6 1. Add this logging config in settings:
    7 {{{
    8 LOGGING = {   
    9     'version': 1,
    10     'disable_existing_loggers': False,
    11     'handlers': {
    12         'socket_handler': {
    13             'class': 'logging.handlers.SocketHandler',
    14             'host': '127.0.0.1',
    15             'port': 9020,
    16         }   
    17     }, 
    18     'loggers': {
    19         'django.request': {
    20             'handlers': ['socket_handler'],
    21             'level': 'INFO',
    22             'propagate': False,
    23         }, 
    24     }   
    25 }
    26 }}}
    27 1. `./manage.py migrate`
    28 1. `./manage.py runserver`
    29 1. `wget http://127.0.0.1:8000/invalid -O /dev//null`
    30 
    31 The exception is this one:
    323
    334{{{
    345--- Logging error ---
    356Traceback (most recent call last):
    36   File "/usr/lib/python3.6/logging/handlers.py", line 633, in emit
     7  File "/data/project/spi-tools-dev/python-distros/Python-3.7.3-install/lib/python3.7/logging/handlers.py", line 630, in emit
    378    s = self.makePickle(record)
    38   File "/usr/lib/python3.6/logging/handlers.py", line 605, in makePickle
     9  File "/data/project/spi-tools-dev/python-distros/Python-3.7.3-install/lib/python3.7/logging/handlers.py", line 602, in makePickle
    3910    s = pickle.dumps(d, 1)
    40   File "/usr/lib/python3.6/copyreg.py", line 65, in _reduce_ex
     11  File "/data/project/spi-tools-dev/python-distros/Python-3.7.3-install/lib/python3.7/copyreg.py", line 65, in _reduce_ex
    4112    raise TypeError("can't pickle %s objects" % base.__name__)
    42 TypeError: can't pickle BufferedReader objects
     13TypeError: can't pickle _Input objects
    4314Call stack:
    44   File "/usr/lib/python3.6/threading.py", line 884, in _bootstrap
    45     self._bootstrap_inner()
    46   File "/usr/lib/python3.6/threading.py", line 916, in _bootstrap_inner
    47     self.run()
    48   File "/usr/lib/python3.6/threading.py", line 864, in run
    49     self._target(*self._args, **self._kwargs)
    50   File "/usr/lib/python3.6/socketserver.py", line 639, in process_request_thread
    51     self.finish_request(request, client_address)
    52   File "/usr/lib/python3.6/socketserver.py", line 361, in finish_request
    53     self.RequestHandlerClass(request, client_address, self)
    54   File "/usr/lib/python3.6/socketserver.py", line 696, in __init__
    55     self.handle()
    56   File "/home/direx/virtualenv/django-2.0/lib/python3.6/site-packages/django/core/servers/basehttp.py", line 154, in handle
    57     handler.run(self.server.get_app())
    58   File "/usr/lib/python3.6/wsgiref/handlers.py", line 137, in run
    59     self.result = application(self.environ, self.start_response)
    60   File "/home/direx/virtualenv/django-2.0/lib/python3.6/site-packages/django/contrib/staticfiles/handlers.py", line 66, in __call__
    61     return self.application(environ, start_response)
    62   File "/home/direx/virtualenv/django-2.0/lib/python3.6/site-packages/django/core/handlers/wsgi.py", line 146, in __call__
     15  File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-packages/django/core/handlers/wsgi.py", line 133, in __call__
    6316    response = self.get_response(request)
    64   File "/home/direx/virtualenv/django-2.0/lib/python3.6/site-packages/django/core/handlers/base.py", line 93, in get_response
    65     extra={'status_code': 404, 'request': request},
    66 Message: 'Not Found: %s'
    67 Arguments: ('/invalid',)
     17  File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-packages/django/core/handlers/base.py", line 136, in get_response
     18    request=request,
     19  File "/data/project/spi-tools-dev/www/python/venv/lib/python3.7/site-packages/django/utils/log.py", line 230, in log_response
     20    exc_info=exc_info,
    6821}}}
    6922
    70 
    71 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.
    72 
    73 I see a few possible solutions for this issue:
    74 
    75 1. Remove the `request` object from the `extra` log message dict. Right now I am not even sure why this is required.
    76 1. Make the entire `request` object pickleable (probably not an easy task)
    77 1. Pass in a reduced (pickable) version of the request object in the `extra` dict
    78 1. Ship a compatible version of `SocketHandler`
    79 
    80 BTW: socket logging is explicitly mentioned in the Django docs:
    81 
    82 > 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**.
    83 
    84 This bug also applies to older Django versions.
Back to Top