Add session ID or some unique ID per session in python logs

Question

I have python flask micro-service in which we're using python's logging library. I want to add request session ID or any other unique ID per session in logs, so i can easily grep the logs for that particular request.

We have on micro-service in java in which we have done the same thing using this.. I want to do the same thing in python.How can i do this.

Also we already have lots of logs in our existing code i want achieve this with modifying existing logs call(or maybe some little modification like passing some argument to log function)

Currently our logging format is like this

formatter = logging.Formatter('[%(asctime)s] - [%(threadName)s] [%(thread)d] - %(levelname)s in %(module)s at %(lineno)d: %(message)s')

Hectoliter

Answer 1

I found this way to add request ids to flask logs on this blog post from McPolemic. I adapted it a bit here.

You will need to implement your own logging.Filter (RequestIdFilter) that will add the req_id attribute to the record. Then, the Formatter (log_formatter) will parse the record and find the req_id and print it.

Since we are creating the req_id from the flask.g.request_id param, it will be the same id used throughout the request.

# server.py
import uuid
import logging
import flask
from flask import Flask

def get_request_id():
    if getattr(flask.g, 'request_id', None):
        return flask.g.request_id

    new_uuid = uuid.uuid4().hex[:10]
    flask.g.request_id = new_uuid

    return new_uuid

class RequestIdFilter(logging.Filter):
    # This is a logging filter that makes the request ID available for use in
    # the logging format. Note that we're checking if we're in a request
    # context, as we may want to log things before Flask is fully loaded.
    def filter(self, record):
        record.req_id = get_request_id() if flask.has_request_context() else ''
        return True


logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

# The StreamHandler responsible for displaying
# logs in the console.
sh = logging.StreamHandler()
sh.addFilter(RequestIdFilter())

# Note: the "req_id" param name must be the same as in
# RequestIdFilter.filter
log_formatter = logging.Formatter(
    fmt="%(module)s: %(asctime)s - %(levelname)s - ID: %(req_id)s - %(message).1000s"
)
sh.setFormatter(log_formatter)
logger.addHandler(sh)

app = Flask(__name__)


@app.route("/")
def hello():
    logger.info("Hello world!")
    logger.info("I am a log inside the /hello endpoint")
    return "Hello World!"


if __name__ == "__main__":
    app.run()

Then, run this server:

python server.py

Finally, run this inside your Python console:

>>> import requests
>>> r = requests.get("http://localhost:5000/"); r.text
'Hello World!'
>>> r = requests.get("http://localhost:5000/"); r.text
'Hello World!'

And the logs will show:

server: 2022-08-01 15:35:26,201 - INFO - ID: 2f0e2341aa - Hello world!
server: 2022-08-01 15:35:26,202 - INFO - ID: 2f0e2341aa - I am a log inside the /hello endpoint
127.0.0.1 - - [01/Aug/2022 15:35:26] "GET / HTTP/1.1" 200 -
server: 2022-08-01 15:35:30,698 - INFO - ID: 1683ba71d9 - Hello world!
server: 2022-08-01 15:35:30,698 - INFO - ID: 1683ba71d9 - I am a log inside the /hello endpoint
127.0.0.1 - - [01/Aug/2022 15:35:30] "GET / HTTP/1.1" 200 -

Note that on different requests, the ids were modified, but they remained unchanged on the same request.

Lincolnlincolnshire

Answer 2

Either use an adapter or add a filter to your log. An adapter would wrap your logger, while with a Filter you would be modifying the LogRecord object.

Using the adapter would work somewhat like this:

import logging

# either user flasks builtin app.logger, or replace with your own logger
request_id = 123 # implement however you prefer
app.logger = CustomAdapter(app.logger, {'request_id': request_id})

and use %(request_id)s in your formatter somewhere. app.logger is the standard logger that flask provides.

Abbotson

Thanks for your reply. I am not understanding where should i put lines you suggested. i have controllers, services and utils functions. i want to add request ID or some unique ID per session, can you please explain little bit more. – Hectoliter

You put these lines at the earliest moment where the logger is available and the id of the request is known, since after that line every log that is created with app.logger will have the request_id property. It depends on the setup of your app but shouldn't be too hard to find the best place. – Abbotson

It is working for same file logs like controller. when control flow move from controller to service function, how can i maintain same ID(created by controller) for services logs also? and also same service function can be called from many controllers! – Hectoliter