Opened 4 years ago
Closed 3 years ago
#32552 closed New feature (fixed)
Allow DiscoverRunner to use a logger instead of printing to stdout
Reported by: | Chris Jerdonek | Owned by: | Chris Jerdonek |
---|---|---|---|
Component: | Testing framework | Version: | 4.0 |
Severity: | Normal | Keywords: | DiscoverRunner, print, logging, stdout, stderr |
Cc: | Triage Stage: | Ready for checkin | |
Has patch: | yes | Needs documentation: | no |
Needs tests: | no | Patch needs improvement: | no |
Easy pickings: | no | UI/UX: | no |
Description
Currently, the DiscoverRunner
class (used when running tests) "logs" by printing directly to stdout. Here is one example:
https://github.com/django/django/blob/7bdd09d016f418719f2d0297f58bd81c5349101d/django/test/runner.py#L592-L596
It would be much better if DiscoverRunner
could instead use a Python logger. The "verbosity" of each print()
statement could be converted to a log message at an appropriate level.
Related to this, passing a --verbosity {0,1,2,3}
(e.g. when using runtests.py) could configure a logger at the appropriate level.
This ticket is related to (but different from) ticket #21429, which is about BaseCommand
. While DiscoverRunner
can be triggered by the test
command, it can also be run separately from a management command, e.g. via runtests
.
Change History (18)
comment:1 by , 4 years ago
comment:2 by , 4 years ago
Is this ticket available? I would like to take up.
I went through the DiscoverRunner
class and I found 7 instances where print
was used.
I believe a good starting approach would be to classify the print statements on the bases of their logging levels.
105: print("\nOpening PDB: %r" % exc_value)
-> DEBUG
142: print("""Subtest failed: ...
-> ERROR
172 & 186 : Two print statements in the check_picklable()
-> ERROR
594: print('Including test tag(s): %s.' % ', '.join(sorted(self.tags)))
-> INFO
596: print('Excluding test tag(s): %s.' % ', '.join(sorted(self.exclude_tags)))
-> INFO
681: print('Skipping setup of unused database(s): %s.' % ', '.join(sorted(unused_databases)))
-> INFO
Let me know if this is the right way to proceed!
comment:3 by , 4 years ago
Only the last three are in the DiscoverRunner
class. The others have different considerations.
I don't think this ticket is necessarily straightforward. For example, I think the behavior should be opt-in (at least for now) because callers might not have logging enabled. I'm not sure yet what the API should be for opting in though. I'm still thinking about it.
I think a good first step would be to add a log(level, msg)
method to the DiscoverRunner
class that preserves the existing print()
behavior. I.e. the signature of the method would match:
https://docs.python.org/3/library/logging.html#logging.Logger.log
And then change the class to use that method for its print statements. The method would use the given level
and compare to self.verbosity
to determine whether the message should be printed.
comment:4 by , 4 years ago
Sure. As suggested, we could add a member function, something like this
def log(self, msg, level=2): if self.verbosity >= level: sys.stderr.write(msg + os.linesep)
Should we stick with print
for now or use sys.stderr.write
/ Logger
?
comment:5 by , 4 years ago
Since this would be a simple refactor with no behavior change, it should be print()
. For the level though, I was thinking a logging level since that's where we're headed and that's the API that most people are familiar with. The method can do the conversion from logging level to "verbosity."
comment:6 by , 4 years ago
Triage Stage: | Unreviewed → Accepted |
---|
I think this is a good move, so let's accept the ticket.
I don't think this ticket is necessarily straightforward. For example, I think the behavior should be opt-in (at least for now) because callers might not have logging enabled. I'm not sure yet what the API should be for opting in though. I'm still thinking about it.
Yes... 🤔 And folks have a hard time getting up and running with logging, so we need to be conscious of that. Part of it is good documentation.
Thanks for all the work you're doing in this area Chris, and thanks for wanting to pick this up Daniyal!
comment:8 by , 4 years ago
Needs documentation: | set |
---|---|
Needs tests: | set |
Patch needs improvement: | set |
comment:9 by , 3 years ago
Has patch: | set |
---|---|
Needs documentation: | unset |
Needs tests: | unset |
Patch needs improvement: | unset |
comment:10 by , 3 years ago
By the way, I think the step after Daniyal's PR would be to change DiscoverRunner
's constructor to accept an optional Python logger
object. Then, DiscoverRunner.log()
could use that, if available, and falling back to the current print()
behavior if self.logger
isn't set.
comment:11 by , 3 years ago
Summary: | Change DiscoverRunner to use a logger instead of print → Allow DiscoverRunner to use a logger instead of printing to stdout |
---|
comment:12 by , 3 years ago
Triage Stage: | Accepted → Ready for checkin |
---|
comment:14 by , 3 years ago
Has patch: | unset |
---|---|
Triage Stage: | Ready for checkin → Accepted |
comment:15 by , 3 years ago
Owner: | changed from | to
---|---|
Status: | new → assigned |
comment:17 by , 3 years ago
Triage Stage: | Accepted → Ready for checkin |
---|
I'll note that one thing this would help with is when testing
DiscoverRunner
. Currently, testing someDiscoverRunner
methods results in undesired console output. If a logger was used instead of printing, then the test framework could take care of this without any extra work. Using a logger would also make it easier to test that certain messages are being emitted, because the testing framework's logging assertions could be used.