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

How should logging in Flask look like? #2023

Closed
untitaker opened this issue Sep 12, 2016 · 20 comments
Closed

How should logging in Flask look like? #2023

untitaker opened this issue Sep 12, 2016 · 20 comments

Comments

@untitaker
Copy link
Contributor

Flask started to ship with a default, hardcoded logging handler. Unfortunately this setup makes it harder to install custom logging setups, because then you'll have to undo all the things Flask did to the app logger, or replace the app.logger entirely. A symptom of this is #1993, where Flask's own logger had to be tweaked yet again such that messages didn't get logged twice (once via Flask's setup, once via the custom one).

My question is: Do we even want Flask to do any logging setup? It appears that this sort of default logging is only useful during development, so maybe it makes sense to set up a default logging handler in the new Flask CLI instead of from within the application.

@jaapz
Copy link
Contributor

jaapz commented Sep 13, 2016

What would happen to the log messages in production, when the current flask logger would be moved to development only?

@davidism
Copy link
Member

The same thing that already happens: you need to add your own logging handler in order to see messages and exceptions generated in production.

@untitaker
Copy link
Contributor Author

Why does that already happen?

On 13 September 2016 10:56:52 CEST, David Lord [email protected] wrote:

The same thing that already happens: you need to add your own logging
handler in order to see messages and exceptions generated in
production.

You are receiving this because you authored the thread.
Reply to this email directly or view it on GitHub:
#2023 (comment)

Sent from my Android device with K-9 Mail. Please excuse my brevity.

@davidism
Copy link
Member

davidism commented Sep 13, 2016

flask.logging seems to configure a log handler for outside debug mode, but I and many others don't see logs unless a handler is explicitly set.

@Rdbaker
Copy link

Rdbaker commented Sep 14, 2016

Python takes a modular approach to its logging by separating the concerns into loggers, handlers, filters, and formatters. Maybe it would be good to have a very simple, yet explicit, default setup for each of these classes with some documentation on how to easily override it, just as flask does for the request and response classes.

@untitaker
Copy link
Contributor Author

That is actually the current state. The problem arises when people use logging.defaultConfig() and messages get logged twice, once with Flask's handler, once with the just configured one.

The question is whether it's a good idea to even have any logging setup by default as it may interfere with the plans of the app developer.

On 14 September 2016 03:44:50 CEST, Ryan Baker [email protected] wrote:

Python takes a modular approach to its logging by separating the
concerns into loggers, handlers, filters, and
formatters
.
Maybe it would be good to have a very simple, yet explicit, default
setup for each of these classes with some documentation on how to
easily override it, just as flask does for the request and response
classes.

You are receiving this because you were mentioned.
Reply to this email directly or view it on GitHub:
#2023 (comment)

Sent from my Android device with K-9 Mail. Please excuse my brevity.

@Rdbaker
Copy link

Rdbaker commented Sep 14, 2016

Er, my suggestion was a little different than the current state, actually.

I was suggesting that, much like the app has a request_class, it could also have a logger_class, handler_class, etc. as opposed to creating the classes inside the of a logging initialization function. So yes, this would set up logging by default.

Are you talking about any logging that a developer might want to do outside of the context of their flask app?
I would probably argue that if the developer is using flask, that's the primary runtime in their environment and logging (even if by default) would probably be desired, and should be easily overridable.

@dwlocks
Copy link

dwlocks commented Dec 13, 2016

I hope I'm not polluting the conversation by adding https://www.bountysource.com/issues/85851-design-issue-with-flask-logger-create_logger

@tuukkamustonen
Copy link

tuukkamustonen commented Dec 13, 2016

Do we even want Flask to do any logging setup?

No. Why should it? If I want to enable logging, I can just logging.defaultConfig() or rather customize it however I want. Why should flask do anything else except the usual:

log = logging.getLogger(__name__)

# then in the code: log.info(...) etc.

Wouldn't it be enough to just mention in the docs that you must initialize logging yourself, as usual, be it through logging.defaultConfig() or logging.config.dictConfig() or however?

@tinproject
Copy link

I spend some days around this, trying to figure out how to implement logging on a Flask app. At the end I decide that, at the current state, the best is to avoid the use of the Flask logger.

Some problems I've found wit the custom Flask's logger:

  • You can't configure the logger in advance because it delete the existing handlers for the logger.
  • It always inserts it's handlers by default, no option to avoid them, so you can get duplicated logs.
  • Too much dependent of the app state, the handlers emit records dependent of the app state so, independently on how you configure the logging hierarchy, the log records could appear or not.
  • Also the Flask logger name could be changed (is a config option), so if it changed a new logger is created and if you have custom configuration it the config must be redone. This is also tricky to detect.
  • It don't play well with the Python's logging system.
  • Some of the Flask's log messages are really werkzeug's ones.

How should logging in Flask look like? Do we even want Flask to do any logging setup?

From my point of view, there should be to parts for logging in Flask:

One part for the library/framework, with a high-level logger node hardcoded to "flask" or "pallets.flask" and child loggers. This will allow 'instrument' the library as #1572 suggests, and also be used by third party libraries like flask-login, flask-wtf, etc.
This part should have no logging configuration at all, perhaps only set the logging level of the high-level node to avoid noise, but no handlers or other setup, and should propagate by default.

Other part, for the Flask app, with a configurable name. To avoid that the reference to the logger could change the name should be pass as an argument to Flask() constructor, e.g.: Flask(..., logger_name="flaskr". This also allows to obtain the logger from the logging module directly and to get child loggers for specific parts of your app.
This part needed some logging setup, if it's not previously done a default handler must be setup, users and servers expect some info about what's happening. To avoid duplication of logs and allow complete logging customization the default handler has to be optional, setted by an argument to Flask() constructor o by inspection the logger hierarchy to find if a proper handler is configured upstream. To log accordingly to app state a filter should be used instead of the two current handlers.

This should be reflected in the docs stating that the preferred way is that the developer configure the logging system and the default config should only be used as a last resort. To allow this the custom formatters and handlers/filters should be exposed to allow import when configuring logging, as @Rdbaker suggests above.

I think that find a way that the Flask's log system goes along with the Logging facility for Python, and not against, is important enough to try to target this discussion to 1.0.

I could help with some code or docs when decisions are made.

@tinproject
Copy link

Trying to learn more about logging I've come across this: http://plumberjack.blogspot.com.es/2010/09/python-logging-functionality-facts-vs.html and I realize why Flask want to pass the logger object around.

Perhaps the first question to make is what logging library is wanted to use by Flask and use it properly. Any option is perfectly fine, but using the stdlib logging as if it was other thing only leads to confusion.

@mscheper
Copy link

mscheper commented May 15, 2017

For one thing, Flask should log chained exceptions. Maybe somebody here would be kind enough to answer my StackOverflow question asking how to get Flask to do this?

@tinproject: Your comment didn't 'confuse' me; I just used the ☹ emoji because it's sad that configuring Flask's logs is apparently difficult. Changing the log format is the first thing I'll want do after My App Works Well Enough, mostly for the above reason, and also to get rid of all the dashes and \ns that clutter up my terminal. I'm glad I found this post; hopefully it'll save me some frustration.

But apparently some people like them, which is fair enough, and a reason logs should be easily configurable. My personal preference would be for a blank line and maybe some dashes each time Flask reloads the app, and for log lines to be timestamped.

@davidism davidism modified the milestone: 1.0 Jun 2, 2017
@mixmastamyk
Copy link

Libraries should not configure logging, they should just log and let the application author configure destinations to their liking. That's best practice for python logging:

Note

It is strongly advised that you do not add any handlers other than NullHandler to your library’s loggers. This is because the configuration of handlers is the prerogative of the application developer who uses your library. The application developer knows their target audience and what handlers are most appropriate for their application: if you add handlers ‘under the hood’, you might well interfere with their ability to carry out unit tests and deliver logs which suit their requirements.

@Rdbaker
Copy link

Rdbaker commented Jun 12, 2017

It'd be important to note that if the recommended practice was the path taken (i.e. add a NullHandler to flask's logger) then Flask would have to drop support for 2.6 (as NullHandler was added in 2.7+ and 3.1+), or else conditionally check whether it can configure a NullHandler

@mixmastamyk
Copy link

mixmastamyk commented Jun 14, 2017

I believe NullHandler is just an optional convenience, not necessary.

Py 2.6 was EOL'd 5 years ago. Though I'm not in a hurry to break it, so checking beforehand couldn't hurt.

BTW, this should be straightened out before a 1.0 release, is there a tag for that?

@ThiefMaster
Copy link
Member

I wouldn't mind seeing 2.6 support go away once Flask reaches v1.0 ;)

@rainiera
Copy link

+1 to following the best practice for Python logging. I don't mind what Flask logs per se but would prefer I had control of the handlers myself since PROD_LOG_FORMAT and DEBUG_LOG_FORMAT in logging.py are distracting for some. Fwiw, I usually call del app.logger.handlers[:] before I add my own loggers in my personal boilerplate.

@davidism
Copy link
Member

davidism commented Jul 25, 2017

I've been looking at this, and "follow best practice" is not as straightforward as it sounds, unfortunately.

  • We're a library, so we shouldn't configure logging. But a lot of people don't think about logging, and we want to show logging messages while running.
  • If we only add handlers when using the flask command, people will be confused when it's not logged in production. This can be solved with documentation, probably.
  • Difficulty arises due to the handlers deciding what to log based on the current state of the app, which can change for various reasons before it starts handling requests. The logger can be accessed before, or after, configuration is loaded. Debug mode can be changed by the run command after configuration is loaded.
  • A similar difficulty occurs with the logger, which uses a custom getEffectiveLevel. Setting the level directly would mean we couldn't reconfigure if debug mode changes, since we wouldn't know at that point if we or the user set the level.
  • We want to log to environ['wsgi.errors'] when in a request.
  • We don't want to log things twice if the user adds a root handler without also configuring the app logger specifically. So propagate needs to be disabled outside of configuration.

Things I've been experimenting with:

  • Add a default config to be passed to dictConfig. Difficult because the config could be changed after the logger is accessed for the first time and the interactions between multiple configs at that point is unclear.
  • Make the default logger name "flask-{import_name}" instead of "{import_name}". However, anything with logger_name makes using dictConfig difficult.
  • Only add one handler, and remove the debug format, just to simplify the story.
  • Add importable logging subclasses that users can use in their own dictConfig. These wouldn't know what app they were configured for though, so would have to use current_app, which means they wouldn't work for logging during setup unless the user knew to push an app context. Or we could use a custom logging.DictConfigurator subclass that injects the app, but that would make it impossible for users to configure logging themselves outside of the Flask app.

@mixmastamyk
Copy link

@davidism, these complex use cases may not be 100% solvable as you are noticing. That's the main reason to leave it up to the (end) developer rather than trying to outsmart them.

(Ask me how I know, haha. I have a kivy app where a non-insignificant amount of code is there to defeat and disable their mandatory logging configuration meant for my own good.)

By all means have a document detailing how to log this and configure that with a list of provided logger names. But when the developer googles "enable logging in a python app" let the standard answer suffice.

I think a "hands off" approach fits better with Flask's breezy design as well.

@davidism
Copy link
Member

I've created #2436 that hopefully simplifies Flask's logging configuration. It also splits out and updates the documentation to help clarify how everything works. If anyone here wants to take a look and make sure it addresses the points brought up here, I'd appreciate it.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Nov 14, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests