pyConnect Logging Duplicate Entries

[dixonwhitmire]

The current pyConnect logging configuration creates duplicate log entries.

2021-02-27 06:38:51,356 - uvicorn.access - INFO - 127.0.0.1:65252 - "GET / HTTP/1.1" 404
2021-02-27 06:38:51,358 - uvicorn.access - INFO - 127.0.0.1:65251 - "GET /favicon.ico HTTP/1.1" 404
2021-02-27 06:38:56,290 - uvicorn.access - INFO - 127.0.0.1:65252 - "GET / HTTP/1.1" 404
2021-02-27 06:38:56,291 - uvicorn.access - INFO - 127.0.0.1:65251 - "GET /favicon.ico HTTP/1.1" 404
2021-02-27 06:38:56,554 - uvicorn.access - INFO - 127.0.0.1:65252 - "GET /docs HTTP/1.1" 200
2021-02-27 06:38:56,709 - uvicorn.access - INFO - 127.0.0.1:65252 - "GET /openapi.json HTTP/1.1" 200
2021-02-27 06:38:56,849 - uvicorn.access - INFO - 127.0.0.1:65252 - "GET /docs HTTP/1.1" 200
2021-02-27 06:38:56,892 - uvicorn.access - INFO - 127.0.0.1:65252 - "GET /openapi.json HTTP/1.1" 200
2021-02-27 06:39:02,029 - pyconnect.routes.status - INFO - Application: pyconnect.main:app
2021-02-27 06:39:02,029 - pyconnect.routes.status - INFO - Application: pyconnect.main:app
2021-02-27 06:39:02,029 - pyconnect.routes.status - INFO - Version: 0.25.0
2021-02-27 06:39:02,029 - pyconnect.routes.status - INFO - Version: 0.25.0
2021-02-27 06:39:02,031 - uvicorn.access - INFO - 127.0.0.1:65256 - "GET /status HTTP/1.1" 200

This appears to be due to Uvicorn log configuration.

It looks like we need to make some updates to the uvicorn logging configuration, specified with log_config to uvicorn.run(), and update our logging.yaml.

[dixonwhitmire]

The uvicorn logging configuration defines a handler for each logger. This causes duplicate entries, since logging is hierarchical. We can address the issue by:

• Passing None to uvicorn.run(log_config)
• Update our logging.yaml to define a handler for the root logger and child loggers as appropriate.

[dixonwhitmire]

New output log

/Users/tdw/projects/lfh/pyconnect/venv/bin/python /Users/tdw/projects/lfh/pyConnect/pyconnect/main.py
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - Loaded logging configuration from logging.yaml
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - **************************************************
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - pyConnect Configuration Settings
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - ==================================================
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - UVICORN_APP: pyconnect.main:app
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - UVICORN_HOST: 0.0.0.0
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - UVICORN_PORT: 5000
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - UVICORN_RELOAD: True
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - ==================================================
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - CERTIFICATE_AUTHORITY_PATH: /Users/tdw/projects/lfh/pyconnect/venv/lib/python3.8/site-packages/certifi/cacert.pem
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - LOGGING_CONFIG_PATH: logging.yaml
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - ==================================================
2021-02-27 09:50:51,933 - pyconnect.server_handlers - INFO - **************************************************
2021-02-27 09:50:51,991 - uvicorn.error - INFO - Application startup complete.