[Django] #34781: Clarify documentation of `request` objects in the `django.server` logging namespace.
Django
namespace.
-----------------------------------------+------------------------
Reporter: Keryn Knight | Owner: nobody
Type: Uncategorized | Status: new
Component: Documentation | Version: dev
Severity: Normal | Keywords:
Triage Stage: Unreviewed | Has patch: 0
Needs documentation: 0 | Needs tests: 0
Patch needs improvement: 0 | Easy pickings: 0
UI/UX: 0 |
-----------------------------------------+------------------------
The docs currently say, of both `django.request` and `django.server`:
> Messages to this logger have the following extra context:
> **request**: The request object that generated the logging message.
However, that appears to be true only in the strictest possible sense,
because as far as I can tell, the `request` on a `django.server` message
under runserver is actually ... the `socket.socket` instance
[https://github.com/python/cpython/blob/f51f0466c07eabc6177c2f64f70c952dada050e8/Lib/socketserver.py#L756
mirrored] as the
[https://github.com/python/cpython/blob/f51f0466c07eabc6177c2f64f70c952dada050e8/Lib/socketserver.py#L805
connection].
Simplest steps I could figure out to show the problem, because frankly
logging in Python is a nightmare, and Django doesn't exactly make it
''better''...
Make a new project `django-admin startproject whatever`
Go and edit `django/utils/log.py` and set up handlers like so:
{{{
"django.request": {
"handlers": ["django.server"],
"level": "INFO",
"propagate": False,
},
"django.server": {
"handlers": ["django.server"],
"level": "INFO",
"propagate": False,
},
}}}
Set the `django.server` formatter like so:
{{{
"formatters": {
"django.server": {
"()": "django.utils.log.ServerFormatter",
"format": "[{server_time}] {request} {message}",
"style": "{",
}
},
}}}
Note the addition of the `{request}` parameter.
Start the server `python manage.py runserver ...`
Open your browser to `/` to see the `The install worked successfully!
Congratulations!` welcome page.
Look at your log output, it'll say something like:
{{{
[17/Aug/2023 11:00:23] <socket.socket fd=7, family=AddressFamily.AF_INET,
type=SocketKind.SOCK_STREAM, proto=0, laddr=('127.0.0.1', 8001),
raddr=('127.0.0.1', 60767)> "GET / HTTP/1.1" 200 10629
}}}
which is ... I ''guess'' you could count it as a request object, though
I'm more inclined to think that the presence of a `.request` attribute
meant the docs could copy-paste/re-use the existing definition
accidentally.
OK so how's that different to the `django.request` logger?
Open your browser to `/404` which I think forces a `django.request` record
via `log_message` Look at your log output again, it'll say something like:
{{{
[17/Aug/2023 11:02:27,574] <WSGIRequest: GET '/404'> Not Found: /404
[17/Aug/2023 11:02:27] <socket.socket fd=7, family=AddressFamily.AF_INET,
type=SocketKind.SOCK_STREAM, proto=0, laddr=('127.0.0.1', 8001),
raddr=('127.0.0.1', 60767)> "GET /404 HTTP/1.1" 404 2101
}}}
Ignoring the fact the server time isn't even formatted the same...
Note how **one** of the records is backed by an actual `WSGIRequest` (and
ultimately can also be be either `HttpRequest` or `ASGIRequest`) which I
think/guess is
[https://github.com/django/django/blob/d25f3892114466d689fd6936f79f3bd9a9acc30e/django/utils/log.py#L246
from here]
But the other is still that pesky socket, which would only have the
requestline + raw requestline etc... That's from
[https://github.com/django/django/blob/d25f3892114466d689fd6936f79f3bd9a9acc30e/django/core/servers/basehttp.py#L185
here I think?]
-----------
Expectations:
Ideally, it'd have the **actual** `HttpRequest` subclass instance, but
that may not actually be possible given where those log messages might
actually occur in the overall machinery. That is, I can't see where you'd
pass it around
So if that's not possible, it'd be lovely to actually tighten up the
documentation to make clear that you won't (necessarily? always?
sometimes?) have that, but only the underlying socket/connection.
--
Ticket URL: <https://code.djangoproject.com/ticket/34781>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
namespace.
Reporter: Keryn Knight | Owner: nobody
Component: Core (Other) | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
--------------------------------------+------------------------------------
Changes (by Natalia Bidart):
* type: Uncategorized => Cleanup/optimization
* component: Documentation => Core (Other)
* easy: 0 => 1
* stage: Unreviewed => Accepted
Comment:
Hello Keryn, thank you for your ticket!
I have reproduced what you described (I preferred to extend the project's
settings to customize the `LOGGING` value instead of changing the source
code, but same result).
The Django code does indeed pass as `extra` logging context what the
`WSGIRequestHandler` is given as `request` by the Python lower level
libraries, so I believe Django can't do anything beyond that. Perhaps a
minor clarification to the docs is worth it.
On that basis, I'm tentatively accepting this report. Would you like to
prepare a patch?
--
Ticket URL: <https://code.djangoproject.com/ticket/34781#comment:1>
Django
namespace.
--------------------------------------+------------------------------------
Reporter: Keryn Knight | Owner: nobody
Type: Cleanup/optimization | Status: new
Component: Core (Other) | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 1 | UI/UX: 0
--------------------------------------+------------------------------------
* has_patch: 0 => 1
Comment:
PR is https://github.com/django/django/pull/17172
--
Ticket URL: <https://code.djangoproject.com/ticket/34781#comment:2>
Django
namespace.
Reporter: Keryn Knight | Owner: nobody
Cleanup/optimization |
Component: Core (Other) | Version: dev
Severity: Normal | Resolution:
| checkin
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 1 | UI/UX: 0
Changes (by Natalia Bidart):
* stage: Accepted => Ready for checkin
--
Ticket URL: <https://code.djangoproject.com/ticket/34781#comment:3>
Django
namespace.
-------------------------------------+-------------------------------------
Reporter: Keryn Knight | Owner: nobody
Cleanup/optimization |
Component: Core (Other) | Version: dev
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
* status: new => closed
* resolution: => fixed
Comment:
In [changeset:"428023e2677aeb80d86b19f90b0c6b82c7cb666d" 428023e2]:
{{{
#!CommitTicketReference repository=""
revision="428023e2677aeb80d86b19f90b0c6b82c7cb666d"
Fixed #34781 -- Updated logging ref docs for django.server's request extra
context value.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/34781#comment:4>
Django
namespace.
-------------------------------------+-------------------------------------
Reporter: Keryn Knight | Owner: nobody
Type: | Status: closed
Cleanup/optimization |
Component: Core (Other) | Version: dev
Severity: Normal | Resolution: fixed
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 1 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Natalia <124304+nessita@…>):
In [changeset:"f55b420277083f2224fe5ef82ccdea66debaa3f3" f55b4202]:
{{{
#!CommitTicketReference repository=""
revision="f55b420277083f2224fe5ef82ccdea66debaa3f3"
[4.2.x] Fixed #34781 -- Updated logging ref docs for django.server's
request extra context value.
Backport of 428023e2677aeb80d86b19f90b0c6b82c7cb666d from main
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/34781#comment:5>