[Django] #29040: test database creation log output doesn't use consistent stream
Django
-------------------------------------+-------------------------------------
Reporter: Chris | Owner: nobody
Jerdonek |
Type: | Status: new
Cleanup/optimization |
Component: Testing | Version: master
framework | Keywords:
Severity: Normal | stdout,stderr,database,creation
Triage Stage: | Has patch: 0
Unreviewed |
Needs documentation: 0 | Needs tests: 0
Patch needs improvement: 0 | Easy pickings: 0
UI/UX: 0 |
-------------------------------------+-------------------------------------
While troubleshooting a test issue, I ran into confusing output that I
tracked down to
[https://github.com/django/django/blob/7fbb1bd00d8a3e9a834de83d36ebcbff15c18938/django/db/backends/base/creation.py#L173-L186
`base/creation.py`] (code shown below) logging its log output to two
different streams. This caused messages to display different from their
actual order.
Specifically, I was seeing the following message:
{{{
Got an error creating the test database: ...
}}}
//after// this message:
{{{
Destroying old test database for alias 'default'
}}}
when the actual order is the reverse:
{{{#!python
sys.stderr.write(
"Got an error creating the test database: %s\n" % e)
if not autoclobber:
confirm = input(
"Type 'yes' if you would like to try deleting the test "
"database '%s', or 'no' to cancel: " % test_database_name)
if autoclobber or confirm == 'yes':
try:
if verbosity >= 1:
print("Destroying old test database for alias %s..." % (
self._get_database_display_str(verbosity,
test_database_name),
))
cursor.execute('DROP DATABASE %(dbname)s' % test_db_params)
self._execute_create_test_db(cursor, test_db_params, keepdb)
except Exception as e:
sys.stderr.write(
"Got an error recreating the test database: %s\n" % e)
sys.exit(2)
}}}
I think the correct solution is for this module to be logging all output
to `stderr` (e.g. like Python's default `logging` behavior) -- reserving
`stdout` for structured / API output. But even just outputting all
messages to the //same// stream would be a big improvement.
I also think it would be a good idea to define a function like `log()`
instead of having `print()` and `sys.stderr.write()` occur throughout.
That would allow logging code to be controlled more centrally (aka DRY).
--
Ticket URL: <https://code.djangoproject.com/ticket/29040>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
-------------------------------------+-------------------------------------
Type: | Status: new
Cleanup/optimization |
Component: Testing framework | Version: master
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
stdout,stderr,database,creation |
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* stage: Unreviewed => Accepted
--
Ticket URL: <https://code.djangoproject.com/ticket/29040#comment:1>
Django
-------------------------------------+-------------------------------------
Type: | Status: new
Cleanup/optimization |
Component: Testing framework | Version: master
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
stdout,stderr,database,creation |
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Chris Jerdonek):
Is there any reason not to be using Python's `logging` module for this
(e.g. inheriting Django's logging configuration)? That would also make the
messages go to `stderr`, which is what we want in my opinion.
--
Ticket URL: <https://code.djangoproject.com/ticket/29040#comment:2>
Django
-------------------------------------+-------------------------------------
Type: | Status: new
Cleanup/optimization |
Component: Testing framework | Version: master
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
stdout,stderr,database,creation |
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Tim Graham):
I guess that would have the similar
[https://docs.djangoproject.com/en/dev/releases/1.10/#runserver-output-
goes-through-logging backwards compatibility issues] as when we changed
runserver to use logging, yes? I don't know, I've always thought of
print/stdout/stderr.write as simpler and "more reliable" than logging.
--
Ticket URL: <https://code.djangoproject.com/ticket/29040#comment:3>
Django
-------------------------------------+-------------------------------------
Type: | Status: new
Cleanup/optimization |
Component: Testing framework | Version: master
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
stdout,stderr,database,creation |
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Chris Jerdonek):
Hmm, I'm never thought of logging as "unreliable." But your point is a
good one. Using logging brings lots of advantages though: custom
formatting, central configuration, etc. I wonder if there is a way to make
Django logging more reliable. Is there one root cause?
Alternatively, I wonder if a helper function or logging tweak could be
used to allow toggling sending messages between Python's `logging` module
and straight `stderr`. Defaulting to the latter would address the
backwards compatibility point you cited (and "reliability") and support an
easier migration path.
--
Ticket URL: <https://code.djangoproject.com/ticket/29040#comment:4>
Django
-------------------------------------+-------------------------------------
Type: | Status: new
Cleanup/optimization |
Component: Testing framework | Version: master
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
stdout,stderr,database,creation |
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Comment (by Tim Graham):
The problem with logging is that we
[https://docs.djangoproject.com/en/dev/topics/logging/#disabling-logging-
configuration document how to disable it]
(c633667da3605208ea5fc137f5322c599f48da69) so we can't generally rely on
it, at least without it being a backwards-incompatible change for users
who have done that.
--
Ticket URL: <https://code.djangoproject.com/ticket/29040#comment:5>
Django
-------------------------------------+-------------------------------------
Type: | Status: new
Cleanup/optimization |
Component: Testing framework | Version: master
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
stdout,stderr,database,creation |
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* has_patch: 0 => 1
Comment:
[https://github.com/django/django/pull/10180 PR]
--
Ticket URL: <https://code.djangoproject.com/ticket/29040#comment:6>
Django
-------------------------------------+-------------------------------------
Cleanup/optimization |
Component: Testing framework | Version: master
Keywords: | Triage Stage: Accepted
stdout,stderr,database,creation |
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
* status: new => closed
* resolution: => fixed
Comment:
In [changeset:"65503ca09798bffbe8226c3a8a7953906042b2ee" 65503ca]:
{{{
#!CommitTicketReference repository=""
revision="65503ca09798bffbe8226c3a8a7953906042b2ee"
Fixed #29040 -- Made test database creation messages use a consistent
output stream.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/29040#comment:7>