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

Set propagate to False on "uvicorn" logger #1288

Merged
merged 6 commits into from Oct 8, 2022

Conversation

guyskk
Copy link
Contributor

@guyskk guyskk commented Dec 9, 2021

Fix #1285

@euri10
Copy link
Member

euri10 commented Dec 10, 2021

this seems to break quite a lots of our tests @guyskk

@guyskk
Copy link
Contributor Author

guyskk commented Dec 10, 2021

@euri10 I see, will check on it.

@guyskk
Copy link
Contributor Author

guyskk commented Dec 11, 2021

Hi @euri10, the failures is because pytest caplog not able to capture propagate=False logger, see also: pytest-dev/pytest#3697

And the caplog_for_logger helper also not work on test config cases, because when create Config object, Config.configure_logging will remove caplog.handler.

A simple work around is set propagate=True before execute tests. Otherwise we need refactor Config class to make it friendly to unit tests.

@euri10
Copy link
Member

euri10 commented Dec 11, 2021

And the caplog_for_logger helper also not work on test config cases, because when create Config object, Config.configure_logging will remove caplog.handler.

mm this is where I'm not too sure, I remeber that pytest issue and I think the fixture was written just for that, and if you look at the way we use it, we do Config first then only we use the fixture so I dont think that explanation is correct, but I may be off

@guyskk
Copy link
Contributor Author

guyskk commented Dec 11, 2021

Yes, the caplog_for_logger works when test logs after create Config object, but it can not capture logs inside Config.__init__.
eg: test_should_warn_on_invalid_reload_configuration, test_reload_dir_is_set and test_non_existant_reload_dir_is_not_set

@Kludex Kludex added this to the Version 0.20.0 milestone May 6, 2022
Copy link
Member

@euri10 euri10 left a comment

Choose a reason for hiding this comment

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

with some tweaks in the explanation and a rebase that solves conflicts it's ready to be merged for me

tests/conftest.py Outdated Show resolved Hide resolved
euri10
euri10 approved these changes Jul 6, 2022
@euri10
Copy link
Member

euri10 commented Jul 6, 2022

thanks a lot @guyskk
@Kludex since you tagged this on the 0.20.0 release I'll let you merge it, or maybe we can point it to this PR release but I'm not sure it exists yet

@Kludex Kludex modified the milestones: Version 0.20.0, Version 0.19.0 Jul 7, 2022
@Kludex
Copy link
Sponsor Member

Kludex commented Jul 7, 2022

It does. Changed the milestone.

The milestones are mainly so I can organize myself. It's a self promise that I'm going to look for the current milestone before the release. :)

# The simple solution is set propagate=True before execute tests.
#
# See also: https://github.com/pytest-dev/pytest/issues/3697
LOGGING_CONFIG["loggers"]["uvicorn"]["propagate"] = True
Copy link
Sponsor Member

Choose a reason for hiding this comment

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

But then... all our users needs to do this if capturing the logs on their setup, right? 🤔

Should we mention this somewhere, or it's fine?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

all our users needs to do this if capturing the logs on their setup, right?

I think if users want to config uvicorn's logs, they should provide full logging config, no needs to set propagate. https://www.uvicorn.org/settings/#logging

And if users only want to config application logs, call logging.basicConfig works as expected, uvicorn's logs will not affected.

Copy link
Sponsor Member

Choose a reason for hiding this comment

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

I mean, if people want to capture those logs on their test, for some reason (?) they need to do the same thing.

Copy link
Member

Choose a reason for hiding this comment

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

But then... all our users needs to do this if capturing the logs on their setup, right? thinking

Should we mention this somewhere, or it's fine?

It introduces a change only for the users who in their tests, use a Config object and are looking for logs if I get it correctly, logging is complex so I'll admit I'm not 100% sure.

I'd be tempted to say it's a rather slim part of people in that case but I may be proven wrong, but there's no harm in saying something like:

Should you use the caplog pytest fixture in your test suite to capture uvicorn logs, you might want to use (the line above) if you use a Config object, please see (test line that explains it)

Copy link
Member

Choose a reason for hiding this comment

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

thoughts on this @guyskk ?

Copy link
Sponsor Member

Choose a reason for hiding this comment

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

(I just wanted to point this out, I don't have any strong opinion about this, jfyk)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I mean, if people want to capture those logs on their test, for some reason (?) they need to do the same thing.

Yes. Maybe mention it in changelog? if those user's tests broken(rare usage), they can easily know why.

Copy link
Member

Choose a reason for hiding this comment

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

ok let's add a note then !

@@ -119,7 +119,7 @@
},
},
"loggers": {
"uvicorn": {"handlers": ["default"], "level": "INFO"},
"uvicorn": {"handlers": ["default"], "level": "INFO", "propagate": False},
"uvicorn.error": {"level": "INFO"},
"uvicorn.access": {"handlers": ["access"], "level": "INFO", "propagate": False},
Copy link
Sponsor Member

Choose a reason for hiding this comment

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

@guyskk Is this "propagate": False still needed?

Copy link
Sponsor Member

Choose a reason for hiding this comment

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

It is.

@Kludex Kludex changed the title Fix duplicate logs when use logging.basicConfig (#1285) Set propagate to False on "uvicorn" logger Oct 8, 2022
@Kludex Kludex merged commit a94781d into encode:master Oct 8, 2022
12 checks passed
Kludex pushed a commit to sephioh/uvicorn that referenced this pull request Oct 29, 2022
Kludex pushed a commit that referenced this pull request Oct 29, 2022
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.

Duplicate logs when use logging.basicConfig in application
3 participants