Use Python’s Logging Module with a Trace Id
Python’s logging module is a powerful tool for debugging and monitoring your code. It allows you to log messages at different levels of severity, and to direct those messages to different destinations, such as the console, a file, or a network socket.
If you have a simple application, you can use the logging module without a trace id, since it’s easy to see which log messages are associated with which requests. However, if you have a more complex application, with multiple threads or processes handling multiple requests, it can be difficult to correlate log messages with the requests that generated them.
In this case, you can use a trace id to associate log messages with requests. A trace id is a unique identifier that is generated for each request, and is included in all log messages generated by that request. This allows you to easily filter log messages by trace id, and see all the log messages associated with a particular request.
Here’s an example of how you can use a trace id with Python’s logging module:
import logging
import uuid
def get_trace_id():
return uuid.uuid4()
class ContextFilter(logging.Filter):
def filter(self, record):
record.trace_id = get_trace_id()
return True
LOG_LEVEL = logging.INFO
logger = logging.getLogger(__name__)
logger.setLevel(LOG_LEVEL)
formatter = logging.Formatter("[%(trace_id)s][%(asctime)s] - %(message)s")
stream = logging.StreamHandler()
stream.setFormatter(formatter)
logger.addHandler(stream)
logger.addFilter(ContextFilter())
logger.info("Hello, world!")
And the output will be:
[e41ee44c-704e-40b6-803c-1ed9844b1f92][2024-08-28 10:09:09,243] - Hello, world!
In this example, we define a get_trace_id
function that generates a unique
trace id for each request using Python’s uuid
module.If you have a different
way of generating trace ids, you can replace this function with your own
implementation.
We also define a ContextFilter
class that adds the trace id to each log
message using the filter
method. We then create a logger, set its log level
to INFO
, and add a stream handler that formats log messages with the trace id
and the timestamp.
Finally, we log a message using the logger, and the trace id is included in the output.
By using a trace id with Python’s logging module, you can easily associate log messages with requests, and quickly identify and debug issues in your application.
Trace ID in Fast API
If you are going to use the the trace id solution proposed above in a Fast API
application, you will see that each request will have a different trace id.
This is because the ContextFilter
class is creating a new trace id for each
call of the logger
object.
In order to get a single trace id for each request, we will have to use
Fast API’s middleware to create a unique trace id for each request and reference
it in the ContextFilter
class.
Just quick info to what the Fast API middleware is, it is a function that intercepts requests and responses, and can be used to perform operations before and after the request is processed.
Here’s an example of how you can use a trace id with Python’s logging module in a Fast API application:
from fastapi import FastAPI
from fastapi import Request
import project.custom_logging as custom_logging
app = FastAPI()
@app.middleware("http")
async def add_process_time_header(request: Request, call_next):
custom_logging.trace_id = custom_logging.get_trace_id()
response = await call_next(request)
return response
and here the the custom_logging.py
file:
import logging
import uuid
from pythonjsonlogger import jsonlogger
trace_id = None
def get_trace_id():
return uuid.uuid4()
class ContextFilter(logging.Filter):
def filter(self, record):
record.trace_id = trace_id
return True
LOG_LEVEL = logging.DEBUG
LOG_FORMAT = "%(asctime)s %(name)s %(levelname)s %(message)s %(trace_id)s"
logging.root.setLevel(LOG_LEVEL)
logHandler = logging.StreamHandler()
formatter = jsonlogger.JsonFormatter(LOG_FORMAT)
logHandler.setFormatter(formatter)
logger = logging.getLogger(__name__)
logger.setLevel(LOG_LEVEL)
logger.addFilter(ContextFilter())
logger.addHandler(logHandler)
This is a simple example of how you can use a trace id with Python’s logging
module in a Fast API application. You can customize the ContextFilter
class
and the get_trace_id
function to suit your needs.
This works, due to sharing of global variables across modules in Python.
In custom_logging.py
, we define a trace_id
variable that will be shared
across modules. We also define a get_trace_id
function that generates a unique
trace id for each request using Python’s uuid
module.
We simply import the custom_logging
module in the main Fast API application
and can do that anywhere else if required, the module itself becomes available
as a global name. Since there is only one instance of each module, any changes
to the module object data are reflected everywhere.
If we would to import the trace_id
variable directly, trace_id
would be
accessible in main.py
but also any changes to trace_id
would not be
reflected anywhere else but main.py
.