When FLASK_ENV=development, Werkzeug does not log HTTP requests

Question

I am working on a simple Flask-RESTful API, which I am very new at, and have run into some problems with logging.

With export FLASK_ENV=development, the Werkzeug logger does not log any HTTP requests such as GET, POST, etc. When export FLASK_ENV=production everything is normal, and a couple of simple logs can look like this:

2020-12-30 14:01:03,723 | INFO | werkzeug | 127.0.0.1 - - [30/Dec/2020 14:01:03] "GET /list/2 HTTP/1.1" 200 -
2020-12-30 14:01:03,742 | INFO | werkzeug | 127.0.0.1 - - [30/Dec/2020 14:01:03] "PUT /list/2 HTTP/1.1" 201 -
2020-12-30 14:01:03,749 | INFO | werkzeug | 127.0.0.1 - - [30/Dec/2020 14:01:03] "DELETE /list/2 HTTP/1.1" 204 -

The main problem probably comes from my logging.dictConfig in my logger.py, since using a simple logging.basicConfig the logs are created as normal. My logger.py looks like this:

import logging as log
from logger.config import dictConfig

dictConfig(
    {
        "version": 1,
        "formatters": {
            "precise": {
                "format": "%(asctime)s | %(levelname)s | %(name)s | %(module)s | %(message)s"
            },
            "brief": {"format": "%(asctime)s | %(levelname)s | %(message)s"},
        },
        "handlers": {
            "console": {
                "class": "logging.StreamHandler",
                "stream": "ext://sys.stdout",
                "formatter": "brief",
                "level": "WARNING",
            },
            "file": {
                "class": "logging.handlers.RotatingFileHandler",
                "formatter": "precise",
                "filename": "logs/api.log",
                "maxBytes": 1024 ** 2,
                "backupCount": 1,
            },
        },
        "root": {"level": "DEBUG", "handlers": ["console", "file"]},
    }
)

In my __init__.py I import log, which means that I can create logs by using log.info() etc. in create_app() or other modules.

However, according to the Flask documentation(https://flask.palletsprojects.com/en/1.1.x/logging/), it might also be caused by the timing of my configuration:

Basic Configuration
When you want to configure logging for your project, you should do it as soon as possible when the program starts. If app.logger is accessed before logging is configured, it will add a default handler. If possible, configure logging before creating the application object.

And I did notice that Werkzeug logs something before any of my logs when export FLASK_ENV=development. I am just surprised this could be the case, since using logging.basicConfig to configure it, it works as a charm. And the first thing I do in __init__.py, is to import the logger; meaning I can't really do it any earlier..

user_11509635 · Answer

I just encountered the same issue, and in attempting to work around it, I discovered a less-than-ideal but workable solution.

Install a package logging_tree. Use logging_tree.printout() to print a complete logging tree.
For me on production environment logger "werkzeug" has desired configuration but in the case of the development environment, the same logger has no configuration which results in a lack of logging.
To solve this problem add "werkzeug" logger to your loggers in dictConfig

My dictConfig:

logging_config = dict(
    version=1,
    formatters={
        "file": {"format": LOG_DETAILED_FORMAT},
        "simple_console": {
            "()": "coloredlogs.ColoredFormatter",
            "format": LOG_SIMPLE_FORMAT,
        },
    },
    handlers={
        "server_console": {
            "level": logging.INFO,
            "class": "logging.StreamHandler",
            "formatter": "simple_console",
        },
        "file": {
            "level": logging.WARNING,
            "class": "logging.handlers.RotatingFileHandler",
            "filename": LOG_FILE_NAME,
            "formatter": "file",
            "maxBytes": 1024 * 1024 * 100,  # ~100 MB
            "backupCount": 10,
        }
    },
    loggers={
        "": {  # Root logger
            "handlers": ["server_console", "file"],
            "level": logging.INFO,
            "propagate": False,
        },
        "werkzeug": {  # Flask
            "handlers": ["server_console", "file"],
            "level": logging.INFO,
            "propagate": False,
        },
    },
)

After this adjustment, the only difference I can see between production and development logging is the first log about the server's IP on which it's running. On production, this log is configured in the desired way, but on development, it's just a normal print. After that, there is no difference in logging.

When FLASK_ENV=development, Werkzeug does not log HTTP requests

1 Answers