[Django] #25684: Runserver doesn't use `LOGGING` configuration
Django
---------------------------------+-----------------
Reporter: fcurella | Owner:
Type: New feature | Status: new
Component: Error reporting | Version: 1.8
Severity: Normal | Keywords:
Triage Stage: Unreviewed | Has patch: 0
Easy pickings: 0 | UI/UX: 0
---------------------------------+-----------------
this is slightly related to https://code.djangoproject.com/ticket/25523
All output in ``core.servers.basehttp`` (and possibly ``fastcgi`` - I
haven't checked that yet) uses ``sys.stderr.write``, bypassing the logging
subsystem.
In order to have it use the ``LOGGING`` settings, I can see 3 options:
a) make it always use ``logger.info(msg)`` and change the default
`LOGGING` settings appropriately
b) make it always use both ``sys.stdout.write`` and ``logger.info``
c) add an option to runserver to switch behaviour
I'm willing to work on the patch (in fact, I have option 2) already
working), I just need to know if this is something we want and what
direction we want to go.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
Reporter: fcurella | Owner:
Type: New feature | Status: new
Component: Error reporting | Version: 1.8
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 fcurella):
* needs_better_patch: => 0
* needs_tests: => 0
* needs_docs: => 0
Old description:
> this is slightly related to https://code.djangoproject.com/ticket/25523
>
> All output in ``core.servers.basehttp`` (and possibly ``fastcgi`` - I
> haven't checked that yet) uses ``sys.stderr.write``, bypassing the
> logging subsystem.
>
> In order to have it use the ``LOGGING`` settings, I can see 3 options:
>
> a) make it always use ``logger.info(msg)`` and change the default
> `LOGGING` settings appropriately
> b) make it always use both ``sys.stdout.write`` and ``logger.info``
> c) add an option to runserver to switch behaviour
>
> I'm willing to work on the patch (in fact, I have option 2) already
> working), I just need to know if this is something we want and what
> direction we want to go.
New description:
this is slightly related to https://code.djangoproject.com/ticket/25523
All output in `core.servers.basehttp` (and possibly `fastcgi` - I haven't
checked that yet) uses ``sys.stderr.write``, bypassing the logging
subsystem.
In order to have it use the `LOGGING` settings, I can see 3 options:
a) make it always use `logger.info(msg)` and change the default `LOGGING`
settings appropriately
b) make it always use both `sys.stdout.write` and ``logger.info`
c) add an option to runserver to switch behaviour
I'm willing to work on the patch (in fact, I have option 2) already
working), I just need to know if this is something we want and what
direction we want to go.
--
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:1>
Django
Reporter: fcurella | Owner:
Type: New feature | Status: new
Component: Error reporting | Version: 1.8
Keywords: | Triage Stage: Unreviewed
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Description changed by fcurella:
Old description:
> this is slightly related to https://code.djangoproject.com/ticket/25523
>
> All output in `core.servers.basehttp` (and possibly `fastcgi` - I haven't
> checked that yet) uses ``sys.stderr.write``, bypassing the logging
> subsystem.
>
> In order to have it use the `LOGGING` settings, I can see 3 options:
>
> a) make it always use `logger.info(msg)` and change the default `LOGGING`
> settings appropriately
> b) make it always use both `sys.stdout.write` and ``logger.info`
> c) add an option to runserver to switch behaviour
>
> I'm willing to work on the patch (in fact, I have option 2) already
> working), I just need to know if this is something we want and what
> direction we want to go.
New description:
this is slightly related to https://code.djangoproject.com/ticket/25523
All output in `core.servers.basehttp` (and possibly `fastcgi` - I haven't
checked that yet) uses ``sys.stderr.write``, bypassing the logging
subsystem.
In order to have it use the `LOGGING` settings, I can see 3 options:
a) make it always use `logger.info(msg)` and change the default `LOGGING`
settings appropriately
b) make it always use both `sys.stdout.write` and `logger.info`
c) add an option to runserver to switch behaviour
I'm willing to work on the patch (in fact, I have option 2) already
working), I just need to know if this is something we want and what
direction we want to go.
--
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:2>
Django
Reporter: fcurella | Owner:
Type: New feature | Status: new
Severity: Normal | Resolution:
Keywords: | Triage Stage: Unreviewed
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by fcurella):
* version: 1.8 => master
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:3>
Django
Reporter: fcurella | Owner:
Type: New feature | Status: new
Severity: Normal | Resolution:
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by fcurella):
* keywords: => runserver logging
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:4>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Unreviewed
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by fcurella):
* owner: => fcurella
* status: new => assigned
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:5>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Changes (by carljm):
* stage: Unreviewed => Accepted
Comment:
I've always wondered why the runserver output didn't use logging; it seems
like an obvious candidate for it. I may be missing something (in which
case hopefully someone else will chime in), but it seems to me that option
(a) -- replace `stderr.write(...)` with logging calls, and adjust the
default logging config so they are still shown -- is the right one.
One reason I can think of why perhaps this hasn't been done is the color
used to mark different response status codes in the runserver output? I
would think it should be possible to preserve that with the right custom
logging handler, though.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:6>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by charettes):
> I've always wondered why the runserver output didn't use logging; it
seems like an obvious candidate for it. I may be missing something (in
which case hopefully someone else will chime in), but it seems to me that
option (a) -- replace stderr.write(...) with logging calls, and adjust the
default logging config so they are still shown -- is the right one.
While I can find the exact discussion I remember there was concerns about
performance.
> One reason I can think of why perhaps this hasn't been done is the color
used to mark different response status codes in the runserver output? I
would think it should be possible to preserve that with the right custom
logging handler, though.
Appropriate formatters should do!
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:7>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by timgraham):
See also #21429 -- BaseCommand should use logging instead of custom output
wrappers.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:8>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by claudep):
I guess the current behavior is simply due to Python itself using
`sys.stderr` in `http.server.BaseHTTPRequestHandler.log_message`.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:9>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by fcurella):
I've done some preliminary work on
https://github.com/django/django/pull/5560
Let me know if anything problematic jumps to the eye, otherwise I can
proceed with tests and docs.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:10>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by fcurella):
Since `runserver` is not supposed to be used in production, I'm really
concerned about performance. I've namespaced the logger so the formatter
should never be called in production (assuming no-one uses `runserver` in
production)
I've done some profiling anyway, and here are the results:
on `master`, `DEBUG = False`:
`ab -k -n 15000 http://127.0.0.1:8000/`:
{{{
Concurrency Level: 1
Time taken for tests: 22.961 seconds
Complete requests: 15000
Failed requests: 0
Non-2xx responses: 15000
Keep-Alive requests: 0
Total transferred: 3435000 bytes
HTML transferred: 1110000 bytes
Requests per second: 653.28 [#/sec] (mean)
Time per request: 1.531 [ms] (mean)
Time per request: 1.531 [ms] (mean, across all concurrent requests)
Transfer rate: 146.09 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.1 0 5
Processing: 1 1 0.4 1 29
Waiting: 1 1 0.3 1 28
Total: 1 2 0.4 1 29
ERROR: The median and mean for the total time are more than twice the
standard
deviation apart. These results are NOT reliable.
}}}
on `master`, `DEBUG = True`:
`ab -k -n 15000 http://127.0.0.1:8000/`:
{{{
Concurrency Level: 1
Time taken for tests: 23.380 seconds
Complete requests: 15000
Failed requests: 0
Keep-Alive requests: 0
Total transferred: 28725000 bytes
HTML transferred: 26505000 bytes
Requests per second: 641.57 [#/sec] (mean)
Time per request: 1.559 [ms] (mean)
Time per request: 1.559 [ms] (mean, across all concurrent requests)
Transfer rate: 1199.81 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.1 0 4
Processing: 1 1 0.8 1 98
Waiting: 1 1 0.8 1 98
Total: 1 2 0.8 1 98
WARNING: The median and mean for the total time are not within a normal
deviation
These results are probably not that reliable.
}}}
Post-patch, `DEBUG = False`:
`ab -k -n 15000 http://127.0.0.1:8000/`:
{{{
Concurrency Level: 1
Time taken for tests: 20.975 seconds
Complete requests: 15000
Failed requests: 0
Non-2xx responses: 15000
Keep-Alive requests: 0
Total transferred: 3435000 bytes
HTML transferred: 1110000 bytes
Requests per second: 715.14 [#/sec] (mean)
Time per request: 1.398 [ms] (mean)
Time per request: 1.398 [ms] (mean, across all concurrent requests)
Transfer rate: 159.93 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.1 0 5
Processing: 1 1 0.5 1 52
Waiting: 1 1 0.5 1 52
Total: 1 1 0.5 1 52
}}}
Post-patch, `DEBUG = True`:
`ab -k -n 15000 http://127.0.0.1:8000/`:
{{{
Concurrency Level: 1
Time taken for tests: 24.314 seconds
Complete requests: 15000
Failed requests: 0
Keep-Alive requests: 0
Total transferred: 28725000 bytes
HTML transferred: 26505000 bytes
Requests per second: 616.92 [#/sec] (mean)
Time per request: 1.621 [ms] (mean)
Time per request: 1.621 [ms] (mean, across all concurrent requests)
Transfer rate: 1153.71 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 1.3 0 139
Processing: 1 2 2.9 1 127
Waiting: 1 1 2.4 1 127
Total: 1 2 3.2 1 140
}}}
Note that the patch skips the formatter if `DEBUG` is `False` by using the
`require_debug_true` filter.
Without the filter, the results are:
Post-patch, `DEBUG = False`, no filter:
`ab -k -n 15000 http://127.0.0.1:8000/`:
{{{
Concurrency Level: 1
Time taken for tests: 21.105 seconds
Complete requests: 15000
Failed requests: 0
Non-2xx responses: 15000
Keep-Alive requests: 0
Total transferred: 3435000 bytes
HTML transferred: 1110000 bytes
Requests per second: 710.72 [#/sec] (mean)
Time per request: 1.407 [ms] (mean)
Time per request: 1.407 [ms] (mean, across all concurrent requests)
Transfer rate: 158.94 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.1 0 6
Processing: 1 1 0.3 1 29
Waiting: 1 1 0.3 1 29
Total: 1 1 0.4 1 29
}}}
Post-patch, `DEBUG = True`, no filter:
`ab -k -n 15000 http://127.0.0.1:8000/`:
{{{
Concurrency Level: 1
Time taken for tests: 23.068 seconds
Complete requests: 15000
Failed requests: 0
Keep-Alive requests: 0
Total transferred: 28725000 bytes
HTML transferred: 26505000 bytes
Requests per second: 650.24 [#/sec] (mean)
Time per request: 1.538 [ms] (mean)
Time per request: 1.538 [ms] (mean, across all concurrent requests)
Transfer rate: 1216.02 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.1 0 12
Processing: 1 1 0.5 1 59
Waiting: 1 1 0.5 1 59
Total: 1 2 0.6 1 59
WARNING: The median and mean for the total time are not within a normal
deviation
These results are probably not that reliable.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:11>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by charettes):
Thanks for the benchmarks.
Here's [https://groups.google.com/forum/#!searchin/django-
developers/django.request|sort:date/django-
developers/154YBWR7K8U/aHtef9DoRFcJ the discussion] I was referring to
when I raised the performance argument point.
> However, there's a cost - we'd be adding the requirement for a logging
configuration for something that is only ever used during development. So
we'd end up complicating the process of deploying the devserver, which is
one of those things that is supposed to Just Work™ out of the box.
> I *think* this would also mean losing the colorisation of devserver
messages, and for me, colorisation of output of the devserver is a higher
priority than the need to filter specific lines out of devserver output
(don't quote me on this one though -- it might be possible to preserve
colorisation. Some experimentation may be required).
> It's also a feature that can be achieved using pipes and grep, which
would be more in line with the broader Unix philosophy.
> In summary: I don't personally see a particularly compelling case for
this feature. However, the real test will be whether you can come up with
an implementation that doesn't overly complicate the deployment of the
devserver for the case that *most* users need it - a simple server that
Just Works™.
#21949 is also a related ticket.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:12>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
Comment (by carljm):
I don't actually see a performance concern mentioned there. There are
three concerns:
1. Adding complexity to out-of-the-box local-dev experience. I think this
is a non-issue, if the default logging config results in the same behavior
we have currently. No additional setup should be needed.
2. Losing colorization of devserver messages. I agree this would be a
problem, but as mentioned above we should be able to preserve this with a
custom formatter.
3. "It's a feature that can be achieved with pipes and grep" -- this
objection could apply to any use of the logging framework in Django. It
doesn't really make sense to allow much of Django's logging output to be
configured using Python's logging framework, but in this specific case
prevent that and require using totally different techniques instead.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:13>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
Changes (by claudep):
* needs_better_patch: 0 => 1
* has_patch: 0 => 1
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:14>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by andreif):
It would be great if we could place the response code at the beginning of
the log message ;)
so it is
{{{
[07/Nov/2015 17:37:05] HTTP/1.1 200 "GET /inbox/" 216874
[07/Nov/2015 17:37:05] HTTP/1.1 304 "GET
/static/CACHE/css/f090a416387d.css" 0
[07/Nov/2015 17:37:05] HTTP/1.1 304 "GET
/static/CACHE/css/df20af4b0d04.css" 0
[07/Nov/2015 17:37:05] HTTP/1.1 304 "GET /static/img/logo.svg" 0
}}}
instead of
{{{
[07/Nov/2015 17:37:05] "GET /inbox/ HTTP/1.1" 200 216874
[07/Nov/2015 17:37:05] "GET /static/CACHE/css/f090a416387d.css HTTP/1.1"
304 0
[07/Nov/2015 17:37:05] "GET /static/CACHE/css/df20af4b0d04.css HTTP/1.1"
304 0
[07/Nov/2015 17:37:05] "GET /static/img/logo.svg HTTP/1.1" 304 0 0ms 2ms
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:15>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by andreif):
It would also be great to have response time in the log message, see
#25704
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:16>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by andreif):
1. I believe it would be better to use `django.server` instead of
`django.request.runserver` for logger name:
{{{
INFO django.server: [07/Nov/2015 20:38:22] "GET / HTTP/1.1" 200 2
}}}
vs
{{{
INFO django.request.runserver: [07/Nov/2015 20:38:22] "GET / HTTP/1.1"
200 2
}}}
2. The date-time should probably not be a part of the message since it's
usually configured in formatter. However, by default python logs without
time info. Maybe `LOGGING` dict in `global_settings.py` can have
`django.server` logging config...
{{{
2015-11-07 20:38:22,627 INFO django.server: [07/Nov/2015 20:38:22] "GET /
HTTP/1.1" 200 2
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:17>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by andreif):
I've just realized that this feature will finally allow to filter out
static requests using logging filters instead of messing in the Django
source code. This is great! :)
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:18>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by fcurella):
According to https://docs.djangoproject.com/en/1.8/topics/logging/#django-
request-logger, the logger should be under `django.request`. Additionally,
4xx should warning and 5xx should be errors.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:19>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by andreif):
As far as I see, `django.request` is used for application and we probably
want to distinguish between those log messages and the ones made by
server...
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:20>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by andreif):
I have moved server time in https://github.com/fcurella/django/pull/3 so
it's not hardcoded in message and used in formatters format.
Discard my comment about global_settings, `DEFAULT_LOGGING` is the right
place :)
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:21>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by fcurella):
> As far as I see, django.request is used for application and we probably
want to distinguish between those log messages and the ones made by server
That's the reason why I went with `django.request.runserver` instead of
just `django.request`.
That said, we can pick a new namespace and update the docs accordingly.
I'd like more consensus on which one to use.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:22>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by andreif):
My changes are merged now and the log message is not changed with this PR,
so the behavior is preserved and I think it's time to merge it as soon as
we agree on the logger name.
I will play with the log message order and parts in #25704
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:23>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by fcurella):
I've noticed just now that Django 1.9 deprecates the `django.request`
logger (https://docs.djangoproject.com/en/1.9/releases/1.9/#changes-to-
the-default-logging-configuration) , so we can use anything under
`django.*`.
Any suggestion?
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:24>
Django
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Comment (by fcurella):
according to the
[https://github.com/django/django/blob/master/docs/releases/1.9.txt#L829-L832
release notes], Django 1.9 drops `django.request`, but the topic guide on
logging
[https://github.com/django/django/blob/master/docs/topics/logging.txt#L471
still mentions it] and does not mention the deprecation.
If I keep the logger name as `django.request.runserver` (or
`django.request`), I'm invalidating the release note. If I change it to
something else, I should proably remove that paragraph from the logging
guide.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:25>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by timgraham):
You can still log using `django.request` -- they'll just propagate to the
`django` logger. I'll give the PR a detailed review later as I am a bit
swamped due to activity from Django Under the Hood sprints. :-)
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:26>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by claudep):
What about logging to `django.runserver`? I don't see what we gain by
using a sublogger of `django.request`. Those messages are for different
components anyway.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:27>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by timgraham):
(I was advocating for either choice myself.)
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:28>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by andreif):
Wouldn't it feel strange if the logger has `runserver` in it's name? As I
see it, user starts the server using `runserver` command. The logging is
done by the server, not the command which started the server. The server
could be started via something else, not related to `runserver` command.
So `django.server` would fit better from my point of view and also
looks/sounds better.
`django.request` deals with application level logging so using it (or its
sublogger) for the server which runs the application is not what one would
expect.
Personally, I don't see any disadvantage of `django.server` but since I am
(seemingly) the only one advocating for it, I wonder why one would not
prefer it?
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:29>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by andreif):
according to the release notes, Django 1.9 drops django.request, but the
topic guide on logging still mentions it and does not mention the
deprecation.
@fcurella, I believe Django 1.9 does not drop `django.request`, just skips
special config for it, see #24526 and
https://github.com/django/django/pull/4389/
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:30>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by claudep):
I'm fine with `django.server` logger, too. Your explanation makes sense.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:31>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by fcurella):
I've updated my PR to use `django.server`. Let me know what else needs to
be done :)
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:32>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
* needs_better_patch: 1 => 0
Comment:
Unchecking `Patch needs improvement` will restack the patch on review
queues.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:33>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by timgraham):
I have some concerns that anyone
[https://docs.djangoproject.com/en/1.9/topics/logging/#disabling-logging-
configuration disabling logging] will be confused why `runserver` doesn't
log anymore. They'll need instructions for how to reenable it. Do the
benefits of this change outweigh the costs to these users?
If we end up replacing the `runserver` machinery with something like
gunicorn (#21978), I wonder if the logging situation would change again
(i.e. would our version of `WSGIRequestHandler` be obsolete?). I don't
know how close that change is to happening (maybe it will never happen),
but I just wanted to raise these points for consideration so we can focus
our time and avoid needlessly annoying our users by making conflicting
changes in one area over several consecutive releases.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:34>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
* needs_better_patch: 0 => 1
Comment:
Assuming we do want to move forward with this, I've reviewed the pull
request.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:35>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 1
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by carljm):
The release notes should of course mention the change. I don't think we
need detailed instructions for how to re-enable it for people who may have
disabled the default logging config; it's enough to say (something like)
"runserver now logs each request to the `django.server` logger instead of
outputting it directly to console; if your logging config overrides
Django's defaults, see the default logging config (link) for an example of
how to configure runserver logging with color output."
Disabling Django's default logging config is an advanced usage, anybody
doing that should know enough about logging to configure things
appropriately from there. (And really, a manual logging config that
silently discards logging output from unknown loggers by default is kind
of broken; someone with such a setup shouldn't be surprised to be missing
some logging output.)
Also, we're talking about a development convenience here, not something
that breaks production code-paths, so the backwards-compatibility concern
level is lower.
I think the benefits of this change are major, in terms of added
flexibility to filter and customize runserver logging output without
needing to hack core Django code.
And any possibility of replacing runserver remains quite remote AFAICS --
there are a lot of hard questions there that remain unanswered, and I'm
not aware of anyone actively working on answering them. I certainly don't
think it's anywhere near imminent enough to provide justification for
halting all improvements to runserver.
So IMO this change is definitely worth moving forward.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:36>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: assigned
Component: Error reporting | Version: master
Severity: Normal | Resolution:
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
* needs_better_patch: 1 => 0
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:37>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Component: Error reporting | Version: master
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
* status: assigned => closed
* resolution: => fixed
Comment:
In [changeset:"0bc5cd628042bf0a44df60a93085a4f991a84dfb" 0bc5cd62]:
{{{
#!CommitTicketReference repository=""
revision="0bc5cd628042bf0a44df60a93085a4f991a84dfb"
Fixed #25684 -- Made runserver use logging for request/response output.
Thanks andreif for the contributing to the patch.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:38>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: closed
Component: Error reporting | Version: master
Severity: Normal | Resolution: fixed
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by Tim Graham <timograham@…>):
In [changeset:"f0a84112ba1c9b253ebbcbd5d6942f01a7bee9d3" f0a84112]:
{{{
#!CommitTicketReference repository=""
revision="f0a84112ba1c9b253ebbcbd5d6942f01a7bee9d3"
Refs #25684 -- Silenced logging output in servers tests.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:39>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: closed
Component: Error reporting | Version: master
Severity: Normal | Resolution: fixed
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by marktranchant):
Replying to [comment:38 Tim Graham <timograham@…>]:
> In [changeset:"0bc5cd628042bf0a44df60a93085a4f991a84dfb" 0bc5cd62]:
> {{{
> #!CommitTicketReference repository=""
revision="0bc5cd628042bf0a44df60a93085a4f991a84dfb"
> Fixed #25684 -- Made runserver use logging for request/response output.
>
> Thanks andreif for the contributing to the patch.
> }}}
Since upgrading to 1.10, my test suite (from {{{manage.py test}}}) now
kicks up this error from {{{ServerFormatter.format()}}} method. Doesn't
affect my tests. Not sure how to flag this error: here, or new ticket?
{{{
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/my-venv/lib/python2.7/site-packages/django/utils/log.py",
line 173, in format
if args[1][0] == '2':
IndexError: tuple index out of range
Logged from file basehttp.py, line 85
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:40>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: closed
Component: Error reporting | Version: master
Severity: Normal | Resolution: fixed
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by timgraham):
New ticket with steps to reproduce.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:41>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: closed
Component: Error reporting | Version: master
Severity: Normal | Resolution: fixed
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by haydenc):
Replying to [comment:40 marktranchant]:
Did this new ticket get created? I can't find it, would be good to have
somewhere to post workarounds even if it's already been addressed.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:42>
Django
-----------------------------------+------------------------------------
Reporter: fcurella | Owner: fcurella
Type: New feature | Status: closed
Component: Error reporting | Version: master
Severity: Normal | Resolution: fixed
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-----------------------------------+------------------------------------
Comment (by timgraham):
I haven't seen a new ticket. Please open one with steps to reproduce.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:43>
Django
Reporter: Flavio Curella | Owner: Flavio
| Curella
Type: New feature | Status: closed
Component: Error reporting | Version: master
Severity: Normal | Resolution: fixed
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Comment (by jonathan-golorry):
I'm not really sure what's going on so I don't want to open a ticket
myself, but I'm consistently getting Mark's "Logged from file basehttp.py"
error with DjangoRestFramework when closing a tab of the browsable API
while it's uploading a file.
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:44>
Django
-------------------------------------+-------------------------------------
Reporter: Flavio Curella | Owner: Flavio
| Curella
Type: New feature | Status: closed
Severity: Normal | Resolution: fixed
Keywords: runserver logging | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Mariusz Felisiak <felisiak.mariusz@…>):
In [changeset:"cdd4ff67d23b80741047eaf6b180dc67a782dfbd" cdd4ff67]:
{{{
#!CommitTicketReference repository=""
revision="cdd4ff67d23b80741047eaf6b180dc67a782dfbd"
Refs #25684 -- Removed double newline from request/response output of
runserver.
Follow up to 0bc5cd628042bf0a44df60a93085a4f991a84dfb.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/25684#comment:45>