[Django] #26688: Inconsistent logging of 5xx and 4xx requests to django.request
Django
-------------------------------+--------------------
Reporter: solarissmoke | Owner: nobody
Type: Uncategorized | Status: new
Component: HTTP handling | Version: master
Severity: Normal | Keywords:
Triage Stage: Unreviewed | Has patch: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------+--------------------
The documentation for `django.request` says:
Log messages related to the handling of requests. 5XX responses are
raised as ERROR messages; 4XX responses are raised as WARNING messages.
The actual behaviour is not quite consistent with this:
- Only `404` and `500` responses are logged to `django.request` - not any
other responses in the `4xx` and `5xx` range.
- `500` responses are only logged if they are the result of an uncaught
exception. The logging happens in
`django.core.handlers.base.handle_uncaught_exception`. If a view manually
sets a `500` response somewhere, this isn't logged.
- The same was true of `404` responses (they were only logged if an
uncaught `Http404` was raised), until the change made in ticket:26504
inadvertently altered this behaviour. After that change, all `404`s are
logged regardless of how they are generated.
I would be happy to submit a patch that addresses this but would like some
guidance on what the best solution is. My initial thoughts are:
- I think Django should log all `5xx` responses, regardless of how they
were generated. This would mean refactoring the logic that does this
logging.
- Either log all `4xx` responses or change the documentation to say that
only `404`s are logged.
--
Ticket URL: <https://code.djangoproject.com/ticket/26688>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
Reporter: solarissmoke | Owner: nobody
Type: Uncategorized | Status: new
Component: HTTP handling | Version: master
Keywords: | Triage Stage: Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by solarissmoke):
* needs_better_patch: => 0
* needs_tests: => 0
* needs_docs: => 0
Old description:
> The documentation for `django.request` says:
>
> Log messages related to the handling of requests. 5XX responses are
> raised as ERROR messages; 4XX responses are raised as WARNING messages.
>
> The actual behaviour is not quite consistent with this:
>
> - Only `404` and `500` responses are logged to `django.request` - not any
> other responses in the `4xx` and `5xx` range.
>
> - `500` responses are only logged if they are the result of an uncaught
> exception. The logging happens in
> `django.core.handlers.base.handle_uncaught_exception`. If a view manually
> sets a `500` response somewhere, this isn't logged.
>
> - The same was true of `404` responses (they were only logged if an
> uncaught `Http404` was raised), until the change made in ticket:26504
> inadvertently altered this behaviour. After that change, all `404`s are
> logged regardless of how they are generated.
>
> I would be happy to submit a patch that addresses this but would like
> some guidance on what the best solution is. My initial thoughts are:
>
> - I think Django should log all `5xx` responses, regardless of how they
> were generated. This would mean refactoring the logic that does this
> logging.
>
> - Either log all `4xx` responses or change the documentation to say that
> only `404`s are logged.
New description:
The documentation for `django.request` says:
Log messages related to the handling of requests. 5XX responses are
raised as ERROR messages; 4XX responses are raised as WARNING messages.
The actual behaviour is not quite consistent with this:
- Only `4xx` and `500` responses are logged to `django.request` - not any
other responses in the `5xx` range.
- `500` responses are only logged if they are the result of an uncaught
exception. The logging happens in
`django.core.handlers.base.handle_uncaught_exception`. If a view manually
sets a `500` response somewhere, this isn't logged.
- The same was true of `404` responses (they were only logged if an
uncaught `Http404` was raised), until the change made in ticket:26504
inadvertently altered this behaviour. After that change, all `404`s are
logged regardless of how they are generated.
- Other `4xx` responses meanwhile are only logged as the result of an
exception (`PermissionDenied` etc.), not if the status code is set
manually.
- `400` responses are logged to `django.security` but not to
`django.request`.
I would be happy to submit a patch that addresses this but would like some
guidance on what the best solution is. My initial thoughts are:
- I think Django should log all `5xx` responses, regardless of how they
were generated. This would mean refactoring the logic that does this
logging.
- Either log all `4xx` responses to `django.request` or change the
documentation to list what specific responses are logged.
--
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:1>
Django
Reporter: solarissmoke | Owner: nobody
Type: Bug | Status: new
Component: HTTP handling | Version: master
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by seocam):
* type: Uncategorized => Bug
* stage: Unreviewed => Accepted
Comment:
The logging behavior is clearly inconsistent with the docs. The documented
behavior is preferable over the current one so that's actually a bug.
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:2>
Django
Reporter: solarissmoke | Owner: seocam
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by seocam):
* owner: nobody => seocam
* cc: seocam@… (added)
* status: new => assigned
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:3>
Django
Reporter: solarissmoke | Owner: seocam
Type: Bug | Status: assigned
Keywords: | Triage Stage: Accepted
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by seocam):
* has_patch: 0 => 1
Comment:
https://github.com/django/django/pull/6716
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:4>
Django
Reporter: solarissmoke | Owner: seocam
Type: Bug | Status: assigned
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by carljm):
* stage: Accepted => Ready for checkin
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:5>
Django
Reporter: solarissmoke | Owner: seocam
Type: Bug | Status: assigned
Keywords: | Triage Stage: Accepted
Easy pickings: 0 | UI/UX: 0
Changes (by timgraham):
* needs_better_patch: 0 => 1
* stage: Ready for checkin => Accepted
Comment:
Patch needs a rebase and I left some additional comments for improvement.
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:6>
Django
Reporter: Samir Shah | Owner: Sergio Oliveira
Type: Bug | Status: assigned
Component: HTTP handling | Version: master
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by Samir Shah):
I've taken the liberty of updating the original PR to work with changes in
the code base since it was created -
https://github.com/django/django/pull/8752. Most of the original work way
done by Sergio.
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:7>
Django
Reporter: Samir Shah | Owner: Sergio Oliveira
Type: Bug | Status: assigned
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by Samir Shah):
* needs_better_patch: 1 => 0
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:8>
Django
Reporter: Samir Shah | Owner: Sergio Oliveira
Type: Bug | Status: assigned
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by Tim Martin):
* needs_better_patch: 0 => 1
Comment:
This looks good to me. I had a minor documentation comment on the patch
review.
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:9>
Django
Reporter: Samir Shah | Owner: Sergio Oliveira
Type: Bug | Status: assigned
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by Samir Shah):
* needs_better_patch: 1 => 0
Comment:
Tim - thanks for the review. I've updated the
[https://github.com/django/django/pull/8752 PR] to address your comments.
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:10>
Django
Reporter: Samir Shah | Owner: Sergio
| Oliveira
Type: Bug | Status: assigned
Keywords: | Triage Stage: Ready for
| checkin
Easy pickings: 0 | UI/UX: 0
Changes (by Tim Martin):
* stage: Accepted => Ready for checkin
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:11>
Django
Reporter: Samir Shah | Owner: Sergio
| Oliveira
Component: HTTP handling | Version: master
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by Tim Graham <timograham@…>):
* status: assigned => closed
* resolution: => fixed
Comment:
In [changeset:"10b44e45256ddda4258ae032b8d4725a3e3284e6" 10b44e45]:
{{{
#!CommitTicketReference repository=""
revision="10b44e45256ddda4258ae032b8d4725a3e3284e6"
Fixed #26688 -- Fixed HTTP request logging inconsistencies.
* Added logging of 500 responses for instantiated responses.
* Added logging of all 4xx and 5xx responses.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:12>
Django
Reporter: Samir Shah | Owner: Sergio
| Oliveira
Type: Bug | Status: closed
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Comment (by nessita <124304+nessita@…>):
In [changeset:"897046815944cc9a2da7ed9e8082f45ffe8110e3" 89704681]:
{{{#!CommitTicketReference repository=""
revision="897046815944cc9a2da7ed9e8082f45ffe8110e3"
Refs #26688 -- Added tests for `log_response()` internal helper.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:13>
Django
Reporter: Samir Shah | Owner: Sergio
| Oliveira
Type: Bug | Status: closed
Component: HTTP handling | Version: dev
Severity: Normal | Resolution: fixed
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Comment (by Natalia <124304+nessita@…>):
In [changeset:"2c8358343ae495d1098e4a1f758df36a184c5407" 2c835834]:
{{{#!CommitTicketReference repository=""
revision="2c8358343ae495d1098e4a1f758df36a184c5407"
[5.2.x] Refs #26688 -- Added tests for `log_response()` internal helper.
Backport of 897046815944cc9a2da7ed9e8082f45ffe8110e3 from main.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/26688#comment:14>
Django
Reporter: Samir Shah | Owner: Sergio
| Oliveira
Type: Bug | Status: closed
Component: HTTP handling | Version: dev
Severity: Normal | Resolution: fixed
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Comment (by Natalia <124304+nessita@…>):
{{{#!CommitTicketReference repository=""
revision="bb92acacac97a4ddcd5a1826ac1e025f3100e246"
[5.1.x] Refs #26688 -- Added tests for `log_response()` internal helper.
Backport of 897046815944cc9a2da7ed9e8082f45ffe8110e3 from main.
}}}
--
Django
Reporter: Samir Shah | Owner: Sergio
| Oliveira
Type: Bug | Status: closed
Component: HTTP handling | Version: dev
Severity: Normal | Resolution: fixed
Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Comment (by Natalia <124304+nessita@…>):
{{{#!CommitTicketReference repository=""
revision="acbe655a0fa1200d2de31c6020f310ba9aa2f636"
[4.2.x] Refs #26688 -- Added tests for `log_response()` internal helper.
Backport of 897046815944cc9a2da7ed9e8082f45ffe8110e3 from main.
}}}
--