Search code examples
pythonloggingazure-application-insights

Python - Logging in multiple modules and child loggers (Azure Monitor)


I have read many docs online (Logging Cookbook, Python reference, many SO posts) but I struggle to make this working.

Context:

  • FastAPI application
  • Docker container for deployment
  • Azure Monitor/Application Insights as logging destination

My needs:

  • (logging) Define handlers, formatters and filters only in one place
  • (logging) Send "info" and below to handler A, above "info" to handler B
  • (project) Structure my project correctly so the above will work

Here is my current project structure (some files omitted for brevity):

dockerfile
main.py
requirements.txt
--logger
----logger.py
--some other module
----module.py

Here is my logger.py file:

import logging
from logging import LogRecord
from datetime import datetime
from pytz import timezone
from opencensus.ext.azure.log_exporter import AzureEventHandler

def log_warning_or_below(record : LogRecord):
    if(record.levelname in [logging.DEBUG, logging.INFO, logging.WARN, logging.WARNING]):
            return True
    return False

def build_custom_events_handler():
    connection_string='InstrumentationKey=xxxxxxxxxxxxxxxxxxxx'
    handler=AzureEventHandler(connection_string=connection_string)
    handler.setLevel(logging.INFO)
    handler.addFilter(log_warning_or_below)

    return handler

def init():
    custom_events_handler = build_custom_events_handler()
    logging.basicConfig(
        format='%(asctime)s - %(message)s',
        level=logging.INFO,
        datefmt='%d-%m-%Y %H:%M:%S',
        handlers=[custom_events_handler]
    )
    logging.Formatter.converter = timetz

init()

And here is my main.py file:

....various imports...
import logger.logger

logger = logger.logger.getLogger('main')
logger.info('Start of main')

def _create_app() -> FastAPI:
    api = FastAPI(
        title='my title',
        description="some desc",
        version='1.0',
    )
    return api

app = _create_app()

@app.post('/myroute')
def do_something():
    logger.info('inside the function')
    return 'my route was hit'

From my comprehension of the hierarchy, the root logger (not named), in my logger.py file, will be configured with the handler and various options. Any child logger to which I send log events (e.g., the logger named "main") will also send records to the root logger, exact?

Currently, this setup doesn't work. I have deployed my app to a Docker container and I run it locally. The FastAPI default logs appear in Azure (the handler) but no other log I send to the logger do.

What am I doing wrong?

Regarding my project structure, I read it is good practice to name your logger such as logger = logging.getLogger(__name__) but I am guessing my structure prevents this from working in the main.py file, as it is located one level higher than the logger.py file?

  • Create a "static" logger, with static methods, in logger.py, to log events (it works, but I prefer having a logger per module)
  • Using a Jupyter notebook, with the logger.py file above and the following code (it works for this test only):
import os
import sys
p = os.path.abspath('..')
sys.path.insert(1, p)
from logger.logger import logging
logger = logging.getLogger('bob')

logger.info('test')
  • Wrapping my head around a DictConfig but it doesn't seem as easy as I think
  • Reading Using logging in multiple modules but many possible solutions and they do not seem to all apply here

Solution

  • I tried this code to Logging in multiple modules with flask File structure

    project/
    |-- dockerfile
    |-- main.py
    |-- requirements.txt
    |-- logger/
    |   |-- __init__.py
    |   |-- logger.py
    |-- some_other_module/
    |   |-- __init__.py
    |   |-- module.py
    
    import logging
    import logging
    from opencensus.ext.azure.log_exporter import AzureLogHandler
    
    def configure_logging():
        connection_string = '  '  
        logger = logging.getLogger(__name__)
        logger.setLevel(logging.INFO)
    
        handler = AzureLogHandler(connection_string=connection_string)
        handler.setLevel(logging.INFO)
    
        formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
        handler.setFormatter(formatter)
    
        logger.addHandler(handler)
    
    
    from logger.logger import configure_logging
    
    
    configure_logging()
    
    
    fastapi_app = FastAPI()
    
    @fastapi_app.get("/")
    def read_root():
        import logging
        logger = logging.getLogger(__name__)
        
      
        logger.info("This is an INFO log message")
        logger.warning("This is a WARNING log message")
        
        return {"message": "Hello, World!"}
    
    
    @fastapi_app.get("/home")
    def home():
        import logging
        logger = logging.getLogger(__name__)
        
        logger.info("Accessed the /home route")
        
        return {"message": "Welcome to the /home route!"}
    
    
    flask_app = Flask(__name__)
    
    @flask_app.route('/')
    def hello_world():
        return 'Hello World'
    
    
    def run_fastapi():
        import uvicorn
        uvicorn.run(fastapi_app, host="0.0.0.0", port=8000)
    
    def run_flask():
        import os
        os.system("gunicorn -b 0.0.0.0:5000 app.main:flask_app")
    
    if __name__ == '__main__':
        fastapi_thread = Thread(target=run_fastapi)
        flask_thread = Thread(target=run_flask)
    
        fastapi_thread.start()
        flask_thread.start()
    

    Output: enter image description here