Sorry, I had those reversed. It works find WITH uWSGI, and fails with the Django dev server.
On Monday, November 7, 2016 at 2:48:14 PM UTC-7, Justin Wilson wrote:
>
> Stumbled across this post while trying to solve the same issue
> *(we've had this issue since 1.10 release, but have kept with 1.9 due to
> this issue).*We're only getting this with Django 1.10+ when running
> behind uWSGI.
> The issue goes away if we just run the Django dev server.
>
> On Thursday, September 15, 2016 at 11:09:13 PM UTC-6, Ben Whale wrote:
>>
>> Thanks for a link to the blob, that is very helpful.
>>
>> You might be right, but the more I look at this the more I think it is a
>> bug.
>>
>> The logging message is generated in django/utils/log.py in
>> the ServerFormatter format() method. If the logging setting is
>>
>> LOGGING = {
>>
>> 'version': 1,
>>
>> 'disable_existing_loggers': False,
>>
>> 'formatters': {
>>
>> 'verbose': {
>>
>> 'format': '%(levelname)s %(asctime)s %(module)s
>> %(process)d %(thread)d %(message)s'
>> },
>>
>> 'simple': {
>>
>> 'format': '%(levelname)s %(message)s'
>>
>> },
>>
>> 'django.server': {
>>
>> '()': 'django.utils.log.ServerFormatter',
>>
>> 'format': '[%(server_time)s] %(message)s %(request)r',
>>
>> }
>>
>> },
>>
>> 'filters': {
>>
>> 'require_debug_false': {
>>
>> '()': 'django.utils.log.RequireDebugFalse',
>>
>> },
>>
>> 'require_debug_true': {
>>
>> '()': 'django.utils.log.RequireDebugTrue',
>>
>> },
>>
>> },
>>
>> 'handlers': {
>>
>> 'console': {
>>
>> 'level': 'DEBUG',
>>
>> 'filters': ['require_debug_true'],
>>
>> 'class': 'logging.StreamHandler',
>>
>> },
>>
>> 'django.server': {
>>
>> 'level': 'INFO',
>>
>> 'class': 'logging.StreamHandler',
>>
>> 'formatter': 'django.server',
>>
>> },
>>
>> 'mail_admins': {
>>
>> 'level': 'DEBUG',
>>
>> 'filters': ['require_debug_false'],
>>
>> 'class': 'django.utils.log.AdminEmailHandler'
>>
>> },
>>
>> 'log_file': {
>>
>> 'level': 'DEBUG',
>>
>> 'filters': ['require_debug_false'],
>>
>> 'class': 'logging.FileHandler',
>>
>> 'formatter': 'verbose',
>>
>> 'filename': './django.log'
>>
>> }
>>
>> },
>>
>> 'loggers': {
>>
>> 'django.server': {
>>
>> 'handlers': ['django.server'],
>>
>> 'level': 'INFO',
>>
>> 'propagate': False,
>>
>> },
>>
>> }
>>
>>
>>
>> }
>>
>> then record.request is a socket object. If, however, the logging setting
>> is
>>
>> LOGGING = {
>>
>> 'version': 1,
>>
>> 'disable_existing_loggers': False,
>>
>> 'formatters': {
>>
>> 'verbose': {
>>
>> 'format': '%(levelname)s %(asctime)s %(module)s
>> %(process)d %(thread)d %(message)s'
>> },
>>
>> 'simple': {
>>
>> 'format': '%(levelname)s %(message)s'
>>
>> },
>>
>> 'django.server': {
>>
>> '()': 'django.utils.log.ServerFormatter',
>>
>> 'format': '[%(server_time)s] %(message)s %(request)r',
>>
>> }
>>
>> },
>>
>> 'filters': {
>>
>> 'require_debug_false': {
>>
>> '()': 'django.utils.log.RequireDebugFalse',
>>
>> },
>>
>> 'require_debug_true': {
>>
>> '()': 'django.utils.log.RequireDebugTrue',
>>
>> },
>>
>> },
>>
>> 'handlers': {
>>
>> 'console': {
>>
>> 'level': 'DEBUG',
>>
>> 'filters': ['require_debug_true'],
>>
>> 'class': 'logging.StreamHandler',
>>
>> },
>>
>> 'django.server': {
>>
>> 'level': 'INFO',
>>
>> 'class': 'logging.StreamHandler',
>>
>> 'formatter': 'django.server',
>>
>> },
>>
>> 'mail_admins': {
>>
>> 'level': 'DEBUG',
>>
>> 'filters': ['require_debug_false'],
>>
>> 'class': 'django.utils.log.AdminEmailHandler'
>>
>> },
>>
>> 'log_file': {
>>
>> 'level': 'DEBUG',
>>
>> 'filters': ['require_debug_false'],
>>
>> 'class': 'logging.FileHandler',
>>
>> 'formatter': 'verbose',
>>
>> 'filename': './django.log'
>>
>> }
>>
>> },
>>
>> 'loggers': {
>>
>> 'django': {
>>
>>
>>
>> 'handlers': ['console', 'mail_admins', 'log_file'],
>>
>> 'level': 'DEBUG',
>>
>> },
>>
>> 'django.server': {
>>
>> 'handlers': ['django.server'],
>>
>> 'level': 'INFO',
>>
>> 'propagate': False,
>>
>> },
>>
>> 'django.request': {
>>
>> 'handlers': ['django.server', 'mail_admins', 'console'],
>>
>> 'level': 'DEBUG',
>>
>> 'propagate': False,
>>
>> },
>>
>> 'django.template': {
>>
>> 'handlers': ['log_file', 'mail_admins', 'console'],
>>
>> 'level': 'DEBUG',
>>
>> 'propagate': False,
>>
>> },
>>
>> }
>>
>> }
>>
>> the format() method is entered twice the first time record.request is a
>> WSGIRequest object and the second time it is a socket.
>>
>> Interestingly there is a definite bug here as the method generates an
>> IndexError. The stack trace is:
>> Traceback (most recent call last):
>> File "/usr/lib/python2.7/logging/__init__.py", line 861, in emit
>> msg = self.format(record)
>> File "/usr/lib/python2.7/logging/__init__.py", line 734, in format
>> return fmt.format(record)
>> File
>> "/home/benwhale/Documents/Projects/mwe/venv/local/lib/python2.7/site-packages/django/utils/log.py",
>>
>> line 173, in format
>> if args[1][0] == '2':
>> IndexError: tuple index out of range
>>
>> This occurs because the args object is (u'/foo',) and I think it's
>> expecting something like (u'/foo', 404, 234324) instead. This occurs on the
>> first pass through the format() method but not the second.
>>
>> In any case, with the appearance of an honest to god bug I'll write up
>> two bug reports and link them. At this point I don't really want to spend
>> to time necessary to determine exactly what's happening.
>>
>> On Friday, 16 September 2016 10:28:45 UTC+10, Tim Graham wrote:
>>>
>>> The logging is coming from here:
>>> https://github.com/django/django/blob/43c471e81c27542e4dc392dfa2310c5a52db35d9/django/core/servers/basehttp.py#L103
>>>
>>> where self.request is indeed a "socketobject"
>>>
>>> I'm not sure if the WSGIRequest object is available at that point, so
>>> possibly this just needs a documentation clarification.
>>>
>>> On Thursday, September 15, 2016 at 7:32:25 PM UTC-4, Ben Whale wrote:
>>>>
>>>> Well my last reply was preemptery.
>>>>
>>>> A minimal working example can be produced via the following commands.
>>>> First navigate to a suitable directory then,
>>>> # virtualenv venv --no-site-packages
>>>> # source venv/bin/activate
>>>> # pip install django
>>>> # django-admin startproject mwe
>>>> # vim mwe/mwe/settings.y
>>>>
>>>> and then entering the following at the end of the settings.py file:
>>>> LOGGING = {
>>>>
>>>> 'version': 1,
>>>>
>>>> 'disable_existing_loggers': False,
>>>>
>>>> 'formatters': {
>>>>
>>>> 'django.server': {
>>>>
>>>> '()': 'django.utils.log.ServerFormatter',
>>>>
>>>> 'format': '[%(server_time)s] %(message)s %(request)r',
>>>>
>>>> }
>>>>
>>>> },
>>>>
>>>> 'handlers': {
>>>>
>>>> 'django.server': {
>>>>
>>>> 'level': 'INFO',
>>>>
>>>> 'class': 'logging.StreamHandler',
>>>>
>>>> 'formatter': 'django.server',
>>>>
>>>> },
>>>>
>>>> },
>>>>
>>>> 'loggers': {
>>>>
>>>> 'django.server': {
>>>>
>>>> 'handlers': ['django.server'],
>>>>
>>>> 'level': 'INFO',
>>>>
>>>> 'propagate': False,
>>>>
>>>> },
>>>>
>>>> }
>>>>
>>>> }
>>>>
>>>> Then :wq
>>>> # cd mwe
>>>> # python manage.py runserver
>>>>
>>>> Navigate to http://127.0.0.1:8000/blargh
>>>>
>>>> The normal error message about routing will show. Switch back to the
>>>> console and you'll see:
>>>>
>>>> # python manage.py runserver
>>>> Performing system checks...
>>>>
>>>> System check identified no issues (0 silenced).
>>>> September 15, 2016 - 23:12:05
>>>> Django version 1.10.1, using settings 'mwe.settings'
>>>> Starting development server at http://127.0.0.1:8000/
>>>> Quit the server with CONTROL-C.
>>>> Not Found: /blargh
>>>> [15/Sep/2016 23:12:09] "GET /blargh HTTP/1.1" 404 1918
>>>> <socket._socketobject object at 0x7fa14d58da60>
>>>>
>>>> That representation of the socket object is being produced by the
>>>> "%(request)r" in the formatter.
>>>>
>>>> Chasing this back through the call stack the request object is set
>>>> in /usr/lib/python2.7/SocketServer.py(652)__init__() as the socket. This
>>>> is
>>>> seems reasonable to me, so I guess some kind of processing of the request
>>>> isn't being performed somewhere.
>>>>
>>>>
>>>> On Friday, 16 September 2016 08:16:09 UTC+10, Ben Whale wrote:
>>>>>
>>>>> Thanks for the reply Tim
>>>>>
>>>>> Some testing seems to indicate that it is an issue with
>>>>> django-rest-framework. When I contact the web server using urls managed
>>>>> by
>>>>> django rest the issues occurs, when I do the same via url managed by
>>>>> vanilla django the request variable in the context object is an instance
>>>>> of
>>>>> WSGIRequest, which is far more sensible.
>>>>>
>>>>> I'm doing to do some more digging today to prove this and, assuming
>>>>> I'm right, will pass the bug onto the django rest guys.
>>>>>
>>>>> Any hints on debugging this? I haven't entered the django code base
>>>>> much before.
>>>>>
>>>>> On Thursday, 15 September 2016 23:21:59 UTC+10, Tim Graham wrote:
>>>>>>
>>>>>> If true, it does seem like a bug. Could you provide a test for
>>>>>> Django's test suite or a sample project to reproduce it?
>>>>>>
>>>>>> On Thursday, September 15, 2016 at 6:53:55 AM UTC-4, Ben Whale wrote:
>>>>>>>
>>>>>>> Hi
>>>>>>>
>>>>>>> What I'd like to do is log the request body whenever the
>>>>>>> django.request logger logs something. I had assumed that the extra
>>>>>>> context
>>>>>>> referred to as request in
>>>>>>> https://docs.djangoproject.com/en/1.10/topics/logging/#django-request
>>>>>>> was something like an HTTPRequest object. It is, however, an instance
>>>>>>> of socket._socketobject.
>>>>>>>
>>>>>>> Is it possible to get data for logging using the socket? For example
>>>>>>> the get parameters, the post data, any information associated to a file
>>>>>>> that was sent like what every has been read out of the socket? What
>>>>>>> about
>>>>>>> the request headers?
>>>>>>>
>>>>>>> Why is a socket passed to the logger? I must admit that I assume
>>>>>>> this to be a bug. The user has a very limited way of interacting with
>>>>>>> the
>>>>>>> socket via the string formatting syntax and the methods of the socket
>>>>>>> (as
>>>>>>> introspected via dir) don't lend them selves to this form of access.
>>>>>>>
>>>>>>> I'm currently using django 1.10 if that helps.
>>>>>>>
>>>>>>> Thanks for any help.
>>>>>>>
>>>>>>>
>>>>>>>
--
You received this message because you are subscribed to the Google Groups
"Django users" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To post to this group, send email to [email protected].
Visit this group at https://groups.google.com/group/django-users.
To view this discussion on the web visit
https://groups.google.com/d/msgid/django-users/f297b70f-9c91-40cf-a773-fdfc25e80b3c%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
