ログに…SQLが…出ない…だと…!?

今、ある仕事(以下、プロジェクトA)で「Django+MySQL」を使っています。
Django では発行された SQL をログ出力する仕組みがあり、具体的にはロガーに以下のような記載をすることで動作します。

# settings.py
LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'simple': {
            'format': '[%(levelname)s] %(asctime)s %(message)s'
        },
    },
    'filters': {
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue', # DEBUG 変数が True の場合のみ処理する
        }
    },
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        }
    },
    'loggers': {
        # django.db.backends パッケージ以下のログを出力する
        'django.db.backends': {
            'handlers': ['console'], # console ハンドラを対象とする
            'level': 'DEBUG', # DEBUG レベルで出力する
            'propagate': True,
        },
    }
}

が、そこで利用しているアプリケーションのログを見ると、全く SQL が出力されていませんでした。

[DEBUG] 2019-02-20 01:47:34,239 (0.000) None; args=(9,)
[DEBUG] 2019-02-20 01:47:34,253 (0.000) None; args=(5,)

本来、上記ログで None となっている箇所に SQL が出力されます。
別の仕事で利用している Django のプロジェクト(以下、プロジェクトB)では問題なく出力されており、「なんでだろう」と頭を悩ませておりました。

MySQL の操作についてはいずれも mysqlclient の 1.4.1 を使っており、プロジェクトA・BそれぞれでDjangoのバージョンが微妙に異なっていた(プロジェクトAは2.0.x、プロジェクトBは2.1.x)ため、組み合わせの問題かと思い調査していました。
少し調べたところ、やはり組み合わせの問題のようで、同様の事象が発生している人がいることを確認しました。

根本原因は「Django 側でクエリ取得のためにアクセスしている属性がライブラリ側から消えたため、SQL を取得できなくなっていた」ということでした。
Django 側の対応としては、これまで _last_executed から取得していたクエリを _executed から取得するように変更したようです(mysqlclient の PR にもそのやりとりが記載されており、このPRで対応されました)。

結局、プロジェクトAでは mysqlclient のバージョンを 1.4.2.post1 にあげ、SQL が出力されることを確認しました。
ライブラリを使う以上、変更点は注意深く見ておく必要があると改めて感じたお話でした。

コメントを残す

メールアドレスが公開されることはありません。 * が付いている欄は必須項目です

CAPTCHA