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 django-users+unsubscr...@googlegroups.com.
To post to this group, send email to django-users@googlegroups.com.
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.
