Logging Practices in Python

Debugging in any language is hard, especially for someone new to the programming language. Debugging is done for many reasons, like finding an issue in the application, performance improvement. This post will go through some of the logging techniques and best practices, and it helps me in debugging quickly.

In any application, logging is vital to identify any issues quickly; without proper logging, we will not be able to debug; Python provides a base framework for logging. We can use various logging levels and functions to log information.

Log Levels

• Exception: this logger function log the message in the "ERROR" level with traceback. It is suitable for places where we have an exception, and we log the traceback in the log.
• Error: this logger function logs the error message in the "ERROR" level. We can log any errors or misbehavior of the application using this level.
• Info: this logger for any information about the flow of the application. logging critical flows of the application will help us to understand how the application works
• Debug: Anything good debugging data but not required in the typical day can be logged through this statement. Typically request and response which contains sensitive information can be logged with this. In any issue, we can change the logger to debug and check what data we received.

Logging Third party

There can be cases we want to understand how a third-party library works. If the library or packages has log statements, we can log them by adding a separate handler in the logger config.

Adding Correlation ID

We can add correlation ID to the process to keep track of the following. It will help in understanding the flow of the application where the issue occurred. If celery being used in the application, we can use taskID as a correlation ID to understand the flow of the processes. the below explains how to set the celery task id the correlation Id

class LogIdFilter(logging.Filter):
  
    def filter(self, record):
        try:
            from celery._state import get_current_task
            task = get_current_task()
            if task and task.request:
                record.logger_id = task.request.id
            else:
                record.logger_id = uuid.uuid4().hex
        except:
            record.logger_id = uuid.uuid4().hex
            record.source_name = 'Self'
        return True

Know all logs

Ensure that you know what places application logs are captured. At times unhandled exceptions gets logged in other system logs, If you using gunicorn, superviord - ensure they have have same log pattern and same log location.

Log some basic information

• if the application is API, we can log some essential pieces of information like IP, URL
• Payloads in Debug mode so that we can stop logging payload in production.
• if your application is protected, log user information like user ID in your logs helps to identify users quickly.
  these information helps in identifying the clients quickly and take action.

Sample logger python logger config

    logging.config.dictConfig(
    {
        "version": 1,
        "disable_existing_loggers": False,
        "formatters": {
            "default": {
                "format": "%(asctime)s | %(levelname)s | %(caller)s | %(logger_id)s | %(name)s | %(module)s:%(funcName)s | %(lineno)d | %(message)s",
            },
            "simple": "%(asctime)s | %(levelname)s | %(source_name)s
        },
        "handlers": {
            "console": {"class": "logging.StreamHandler", "formatter": "default",},
        },
        "loggers": {
            "": {"level": LOGLEVEL, "handlers": ["console"],},
            "product": {
                "level": LOGLEVEL,
                "handlers": ["console"],
                "propagate": False,
            },
            "client": {
                "level": LOGLEVEL,
                "handlers": ["console"],
                "propagate": False,
            },
        },
    }
)