Flask: How should logging in Flask look like?

[untitaker]

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]

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

[davidism]

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]

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:
https://github.com/pallets/flask/issues/2023#issuecomment-246618501

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

[davidism]

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]

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]

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:
https://github.com/pallets/flask/issues/2023#issuecomment-246880948

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

[Rdbaker]

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]

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

[tuukkamustonen]

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]

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]

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]

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.

[mixmastamyk]

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:

• https://docs.python.org/3/howto/logging.html#configuring-logging-for-a-library
• http://docs.python-guide.org/en/latest/writing/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]

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]

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]

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

[rainiera]

+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]

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]

@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]

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.