Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Preserve logs that LoggingPanel would previously overwrite #1603

Merged
merged 4 commits into from
Apr 12, 2022

Conversation

riwatt
Copy link
Contributor

@riwatt riwatt commented Apr 2, 2022

This might solve the root cause of issues reported in #695 #1078 and #1300


Summary:
LoggingPanel upon its import, changes the Python interpreter's root logger to log into a handler that collects its records for the LoggingPanel's display. However for users that don't explicitly configure the root logger this looks like the Debug Toolbar suppresses their logs that previously went to standard error.
With this commit, the logs will still keep going to standard error even if the LoggingPanel is installed, but only if the root logger has not been explicitly configured with a handler yet.
This behavior will make it so that installing DDT won't break logging neither for users that already have logging customizations nor for users that have an out-of-the-box django default logging setup.

Also: change LOGGING config in tests/settings.py because now DDT's own test suite would show more logs without an explicit config.

@riwatt riwatt changed the title Preserve logs that LoggingPanel would previously overwrite. Preserve logs that LoggingPanel would previously overwrite Apr 2, 2022
@riwatt riwatt force-pushed the preserve-lastresort-log branch from 78143c2 to 945bd92 Compare April 2, 2022 08:01
Copy link
Member

@matthiask matthiask left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks! Looks good.

I was wondering for a moment if it would be possible to use lastResort for the toolbar but that would probably be more brittle and less obvious.

I'm always worrying a bit about module-level configuration because of the dependency on import ordering. This will be fine though since Django initializes logging long before the toolbar is initialized for the first time in the middleware.

@tim-schilling
Copy link
Member

Is it possible to test this in the test suite? Otherwise this looks good, but needs verification.

@riwatt
Copy link
Contributor Author

riwatt commented Apr 2, 2022

Is it possible to test this in the test suite? Otherwise this looks good, but needs verification.

Sorry I didn't mention it, but I verified this with a minimal django app by varying its logging configs.
Would it be sufficient if I describe that repro here?
Or maybe I can add something to the example app that can show before and after behavior?

Fully covering this within the test suite might be difficult because of the above mentioned concerns of the original code overriding global behavior at import time. I will look into it though, but let me know if repro is enough.
Thanks for the quick reviews!

@matthiask
Copy link
Member

matthiask commented Apr 2, 2022

I agree with the sentiment that adding a unittest which fully covers this may be hard to do. Maybe it's feasible to add a regression test which emits a logging message without any configured loggers and which verifies that the output appears on sys.stderr? (maybe mock stderr if necessary) I think this should cover the expected default behavior and would be sufficient.

If that proves hard to do then I think a description is fine. We're all volunteering here :)

@riwatt riwatt force-pushed the preserve-lastresort-log branch from 945bd92 to 5fc9a64 Compare April 4, 2022 08:06
riwatt added 3 commits April 4, 2022 01:17
LoggingPanel upon its import, changes the Python interpreter's root
logger to log into a handler that collects its records for the
LoggingPanel's display.

However for users that don't explicitly configure the root logger this
looks like the Debug Toolbar suppresses their logs that previously
went to standard error.

With this commit, the logs will still keep going to standard error
even if the LoggingPanel is installed, but only if the root logger has
not been explicitly configured with a handler yet.

This behavior will make it so that installing DDT won't break logging
neither for users that already have logging customizations nor for
users that have an out-of-the-box django default logging setup.

Also: change LOGGING config in tests/settings.py because now DDT's own
test suite would show more logs without an explicit config.
@riwatt riwatt force-pushed the preserve-lastresort-log branch from 5fc9a64 to f470343 Compare April 4, 2022 08:18
@riwatt
Copy link
Contributor Author

riwatt commented Apr 4, 2022

@matthiask I rebased this branch so its first commit is now a regression test.
If you run the testsuite against that commit only then it will fail, but then you can see that the final commit fixes it.
I also added my original reproducer app into this repo: https://github.com/riwatt/ddjt_logging. The readme there describes the steps I used to test the fix.


Re: the precommit.ci failure is because of psf/black#2964
I ran it locally with black==22.3.0 without any issues.
Edit: looks like black / precommit is fixed in #1598

@matthiask
Copy link
Member

Thanks! Let's merge this, everything makes a lot of sense to me.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants