Trong quá trình phát triển phần mềm, ghi log là một hoạt động quan trọng phục vụ cho người lập trình. Khi một chương trình chạy không như mong muốn, ta cần phải biết sai chỗ nào để sửa. "Ghi log" là bắt chương trình của ta "kể lại" diễn biến hoạt động của nó, giá trị của một vài biến lúc ấy, để giúp ta kiểm tra lại được chỗ nào sai.

Vậy mình thường dùng thư viện nào cho việc ghi log?

Như đã đề cập trong bài "Khởi đầu dự án Python như thế nào để thuận tiện phát triển lên", Python có một thư viện chuẩn logging, mà điểm lợi là khi các thư viện cùng dùng nó, ta có thể từ tầng ứng dụng điều chỉnh "log level" cho tầng thư viện mà không cần can thiệp vào code của thư viện ấy. Vì lẽ đó, đương nhiên các ứng dụng của mình cũng dùng logging nhưng cũng kèm thêm một số thư viện bổ trợ khác để thỏa mãn nhu cầu / sở thích cá nhân.

Một trong những nhu cầu của mình là cần màu sắc phân biệt, để truy tìm điểm cần tìm cho dễ, ít nhất là các log level cần có màu sắc khác nhau để dễ dàng lọc lựa, bỏ qua thông điệp ít quan trọng. Về khoản màu sắc thì mình ưa dùng thư viện rich. Nó thậm chí còn hơn cả mong đợi vì nó còn nhận diện và tô màu theo "kiểu dữ liệu", ví dụ dữ liệu số có màu khác, dữ liệu chuỗi, đối tượng... có màu khác.

Để tích hợp rich vào việc tô màu cho log thì ta dùng class rich.logging.RichHandler làm handler cho logging. Cách làm cơ bản thì có thể theo tài liệu của rich. Để tích hợp vào một dự án Django thì ta có thể thêm vào cấu hình LOGGING trong settings.py:

import os


LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
        },
        'rich': {
            'level': 'DEBUG',
            'class': 'rich.logging.RichHandler' if os.getenv('TERM') else 'logging.StreamHandler',
        },
    },
    'root': {
        'level': 'WARNING',
        'handlers': ['console'],
    },
    'loggers': {
        # Daphne always print color codes, so we bypass rich handler
        'django.channels.server': {
            'level': 'INFO',
            'handlers': ['console'],
            'propagate': False,
        },
        'our_app': {
            'level': 'INFO',
            'handlers': ['rich'],
            'propagate': False,
        }
    }
}

Trong ví dụ trên, có hai chi tiết đáng lưu ý:

• Ta chỉ sử dụng rich.logging.RichHandler khi ứng dụng đang kết nối vào Terminal (thông qua kiểm tra os.getenv('TERM')). Bởi vì trong một số môi trường chạy, ví dụ trong Docker container, trong CI/CD, "thiết bị console" không phải là Terminal sẽ không hiểu được mã màu, nếu ta vẫn sử dụng rich thì console sẽ in nguyên văn các mã màu khiến cho nội dung log nhìn rất rối rắm.
• Ta cũng không sử dụng rich cho các thông điệp log sinh ra bởi module django.channels.server, vì module này tạo ra mã màu trước khi thông điệp log đến được với handler rich, khiến nội dung cuối cùng bị pha trộn mã tùm lum.

Lưu ý, khi sử dụng rich, bạn không nên chạy ứng dụng qua PyCharm, vì PyCharm sẽ lược bỏ hết các mã màu, khiến việc sử dụng rich thành vô nghĩa.

Như ta đã biết, rich phù hợp với môi trường "development" vì khi đó lập trình viên đang thao tác qua Terminal. Khi chạy trên môi trường "production" (server) thì ứng dụng không kết nối với Terminal nên dùng rich là vô nghĩa, nhưng nếu ta vẫn muốn có log màu sắc thì sao? Trên server thì tôi luôn chạy ứng dụng bằng systemd, khi đó thì journald sẽ ở bên, tôi sẽ cho log ghi vào journald để có được log màu sắc. Journald chỉ tô màu log theo cấp độ chứ không phong phú như rich, nhưng như thế cũng đủ.

Để tích hợp journald với ứng dụng Django thì ta cấu hình LOGGING trong settings.py như sau:

import importlib.util

from chameleon_log.detectors import is_connected_journald


INSIDE_SYSTEMD = bool(importlib.util.find_spec('systemd')) and is_connected_journald()


_LOGGING_HANDLERS = {
    'console': {
        'level': 'DEBUG',
        'class': 'logging.StreamHandler',
        'formatter': 'verbose',
    },
    'rich': {
        'level': 'DEBUG',
        'class': 'rich.logging.RichHandler' if os.getenv('TERM') else 'logging.StreamHandler',
        'formatter': 'tiny' if os.getenv('TERM') else 'verbose',
    },
}
_LOGGING_FORMATTERS = {
    'verbose': {'format': '%(levelname)s %(asctime)s %(module)s: %(message)s'},
    # This formatter is for writing to Journald. Journald already tracks datetime, 
    # we don't need to include it in the log message.
    'tiny': {
        'format': '%(message)s',
        'datefmt': '[%X]',
    },
}
if INSIDE_SYSTEMD:
    _LOGGING_HANDLERS['journald'] = {
        'level': 'DEBUG',
        'class': 'systemd.journal.JournalHandler',
        'formatter': 'tiny',
    }
CONSOLE_HANDLER = 'console' if is_in_testing() else ('journald' if INSIDE_SYSTEMD else 'rich')

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'root': {
        'level': 'WARNING',
        'handlers': [CONSOLE_HANDLER],
    },
    'formatters': _LOGGING_FORMATTERS,
    'handlers': _LOGGING_HANDLERS,
    'loggers': {
        'django.db.backends': {
            'level': 'WARNING',
            'handlers': [CONSOLE_HANDLER],
            'propagate': False,
        },
        # Daphne always print color codes, so we bypass rich handler
        'django.channels.server': {
            'level': 'INFO',
            'handlers': ['console'],
            'propagate': False,
        },
        'our_app': {
            'level': 'INFO',
            'handlers': [CONSOLE_HANDLER],
            'propagate': False,
        },
    },
}

Đoạn code ví dụ trên có nhiều bước kiểm tra, để thích ứng trong nhiều môi trường chạy khác nhau, ví dụ:

• Trước khi dùng Journald làm log handler thì ta kiểm tra xem ứng dụng có đang kết nối với journald hay không, và đã cài thư viện systemd-python hay chưa.
• Sử dụng rich làm handler nếu đang trong môi trường "development" và đang kết nối với một Terminal.
• Khi đang chạy unittest thì chỉ dùng handler console thuần (không màu sắc).
• Dùng handler console thuần trong các trường hợp còn lại.

Ngoài vấn đề màu sắc thì mình còn nhu cầu sử dụng cú pháp hiện đại để viết code để sinh log nữa. Nếu dùng thư viện chuẩn logging thì phải dùng cú pháp cũ, ví dụ:

logger.info('To relink subjects for "%s" (%d) course...', course, course.pk)

Trong khi tôi muốn dùng cú pháp mới, ví dụ:

logger.info('To relink subjects for "{}" ({}) course...', course, course.pk)

Để làm được điều này thì tôi dùng thư viện Logbook rồi cho log từ Logbook đẩy qua logging.

Trên đây là những thư viện ưa thích của tôi cho việc ghi log. Tất nhiên nó chưa phải là hay nhất vì kho tàng của Python rất phong phú, có thể còn nhiều thư viện hay ho nữa (ví dụ tôi có thấy loguru nhưng chưa thử). Ngoài ra, khi làm việc bên Rust, tôi dùng tracing cũng thấy hay, phù hợp cho ứng dụng đa luồng, hoặc bất đồng bộ với nhiều task con, vì nó giúp chia log theo luồng, hoặc theo một "đường ống". Dường như đã có thư viện Python theo xu hướng này nhưng tôi chưa tìm ra.