Search code examples
pythonloggingstarletteuvicorn

Python Logging - How do I disable a package's Logging?


I am being driven mad by this issue. I want to just log using my basicConfig, but the module (uvicorn) is also logging to the file as well.

Example:

2019-11-27 14:44:29,595 - uvicorn - INFO - ('127.0.0.1', 62211) - "GET /consumption/xyz HTTP/1.1" 200

('127.0.0.1', 62211) - "GET /consumption/xyz HTTP/1.1" 200

I don't want the 2nd message to appear because it is a duplicate...how do I disable that?

Update: Code used...

formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
logging.getLogger("snowflake.connector.network").disabled = True # remove snowflake network logging
logging.getLogger("snowflake.connector.connection").disabled = True
logging.getLogger('snowflake.connector').setLevel(logging.INFO)
logging.getLogger('boto3').setLevel(logging.INFO)
logging.getLogger('botocore').setLevel(logging.CRITICAL)
logging.getLogger('urllib3').setLevel(logging.CRITICAL)
logging.basicConfig(filename=f'{CFG.get("log_path")}',
                    filemode='w',
                    level=logging.DEBUG,
                    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s'
                    )
rotating = RotatingFileHandler(f'{CFG.get("log_path")}', maxBytes=1024*1024*500, backupCount=4)
logging.getLogger('').addHandler(rotating)

Log after setting access-log = False. I hit the API a few times:

2019-12-02 10:16:26,635 - uvicorn - WARNING - auto-reload only works when app is passed as an import string.
2019-12-02 10:16:26,656 - uvicorn - INFO - Started server process [20653]
2019-12-02 10:16:26,656 - uvicorn - INFO - Waiting for application startup.
2019-12-02 10:16:26,657 - uvicorn - INFO - Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
2019-12-02 10:16:43,379 - uvicorn - INFO - Shutting down
2019-12-02 10:16:43,479 - uvicorn - INFO - Waiting for application shutdown.
2019-12-02 10:16:43,479 - uvicorn - INFO - Finished server process [20653]
Finished server process [20653]

Log when access_log = True:

2019-12-02 10:17:44,438 - uvicorn - WARNING - auto-reload only works when app is passed as an import string.
2019-12-02 10:17:44,459 - uvicorn - INFO - Started server process [20791]
2019-12-02 10:17:44,459 - uvicorn - INFO - Waiting for application startup.
2019-12-02 10:17:44,460 - uvicorn - INFO - Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
2019-12-02 10:17:58,571 - uvicorn - INFO - ('127.0.0.1', 55861) - "GET / HTTP/1.1" 200
('127.0.0.1', 55861) - "GET / HTTP/1.1" 200

Solution

  • logging.basicConfig adds a Handler. Then you go and add another. Both directed to the same file.

    logging.basicConfig(filename=f'{CFG.get("log_path")}',
                        filemode='w',
                        level=logging.DEBUG,
                        format='%(asctime)s - %(name)s - %(levelname)s - %(message)s'
                        )
    rotating = RotatingFileHandler(f'{CFG.get("log_path")}', maxBytes=1024*1024*500, backupCount=4)
    logging.getLogger('').addHandler(rotating)
    

    So to see how to fix this it is best to look at what logging.basicConfig actually does:

    def basicConfig(**kwargs):
    
        _acquireLock()
        try:
            if len(root.handlers) == 0:
                filename = kwargs.get("filename")
                if filename:
                    mode = kwargs.get("filemode", 'a')
                    hdlr = FileHandler(filename, mode)
                else:
                    stream = kwargs.get("stream")
                    hdlr = StreamHandler(stream)
                fs = kwargs.get("format", BASIC_FORMAT)
                dfs = kwargs.get("datefmt", None)
                fmt = Formatter(fs, dfs)
                hdlr.setFormatter(fmt)
                root.addHandler(hdlr)
                level = kwargs.get("level")
                if level is not None:
                    root.setLevel(level)
        finally:
            _releaseLock()
    

    Inlining basicConfig results in:

    root = logging.getLogger('')
    if len(root.handlers) == 0:
        filename = f'{CFG.get("log_path")}'
        mode = 'w'
        hdlr = FileHandler(filename, mode)
        fs = '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
        dfs = None
        fmt = Formatter(fs, dfs)
        hdlr.setFormatter(fmt)
        root.addHandler(hdlr)
        root.setLevel(logging.DEBUG)
    
    rotating = RotatingFileHandler(f'{CFG.get("log_path")}', maxBytes=1024*1024*500, backupCount=4)
    root.addHandler(rotating)
    

    Can you see the issue? The same file is setup with a Handler twice so to fix this write it as:

    root = logging.getLogger('')
    if len(root.handlers) == 0:
        filename = f'{CFG.get("log_path")}'
        hdlr = RotatingFileHandler(filename, maxBytes=1024*1024*500, backupCount=4)
        fs = '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
        fmt = Formatter(fs)
        hdlr.setFormatter(fmt)
        root.addHandler(hdlr)
        root.setLevel(logging.DEBUG)