Djangoのlogにユーザー情報など出力

Djangoのログにリクエストユーザー情報などLogRecord属性にない情報を出力しようとすると、

logger.info(message, extra={'username' : request.user.username})

こんな感じのが見つかるけどちょっと違うな～と。ルールを守ってくれない開発メンバーがいたり、自分で書いたログにしか効かないし、と思ってたところ解決策がありました。

概要

• Middlewareを使ってリクエスト時にユーザー情報をthreading.local()に設定
• logging.filterでthreading.local()のユーザー情報をLogRecordに追加
• settings.pyのLOGGINGの設定

Middleware

• requestからusernameを取得。（APIだったらJWTをpharseしてユーザー情報を取得したりとか…）
• 上記で取得したusernameをthreading.local()に設定。(後述のfilterから参照するため)
• self.get_response(request)の後はクリアする意味でNoneを設定

import logging
import threading

local = threading.local()

class CustomAttrMiddleware:
    """
    logに出力するカスタム項目を取得するMiddleware
    """
    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        """
        クライアントからのリクエスト時にrequestのusernameを取得して
        threading.local()に一時保存
        """
        if request.user:
            setattr(local, 'user', request.user.username)
        else:
            setattr(local, 'user', None)

        response = self.get_response(request)

        # response時はクリアしておく
        setattr(local, 'user', None)

        return response

filter

• Middlewareでthreading.local()に設定したusernameをLogRecordに設定。
• 必ずTrueをreturnする。

class CustomAttrFilter(logging.Filter):
    """
    logにカスタム項目を出力するためのfilter
    """
    def filter(self, record):
        record.user = getattr(local, 'user', None)
        return True

settings.py

• 上記で作成したMiddlewareを追加。
• LOGGINGのformattersにユーザーの出力形式（user=%(user)s）を追加
• LOGGINGのfiltersに上記で作成したfilterを追加
• 追加したfilterをLOGGINGのhandlersで使用するよう設定

MIDDLEWARE = [
     ...
    'middleware.custom_logging.CustomAttrMiddleware',
]

LOGGING = {
     ...
    'formatters': {
        'verbose': {
            'format': '%(levelname)s %(asctime)s %(module)s '
                      '%(process)d %(thread)d user=%(user)s %(message)s'
        },
    },
    'filters' : {
        'custom': {
            '()': 'middleware.custom_logging.CustomAttrFilter'
        },
    },
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'verbose',
            'filters': ['custom']
        },
    },
     ...
}

views（動作確認用）

class LoggingExceptListView(generics.ListAPIView):
    """
    ログでexception出力を確認するためのListView
    """
    def list(self, request, *args, **kwargs):
        """
        Exceptionをraiseするだけ
        """
        raise Exception('ログ確認用')

log出力結果

• 上記の動作確認用viewsを実行
• 以下のログの"user=CustomAttrUser"の部分

ERROR 2020-05-06 17:12:02,703 log 13516 10376 user=CustomAttrUser Internal Server Error: /sample_api/logging-exp/
Traceback (most recent call last):
  File "C:\ProgramData　...
　...  raise Exception('ログ確認用')

ソース

参考文献

• Django: Adding a Custom Attribute to All Log Lines