今、ある仕事(以下、プロジェクト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)ため、組み合わせの問題かと思い調査していました。
少し調べたところ、やはり組み合わせの問題のようで、同様の事象が発生している人がいることを確認しました。
Django2.0.x と mysqlclient 1.4.1 だとクエリログが出ない。
— Kazuki@お仕事随時募集中 (@kzkamago0721) 2019年2月20日
どちらかだけでもあげるとこの問題は解決する。
自分がかかわっているプロジェクトでも発生していて昨夜調査してたけど、やっぱり組み合わせの問題やったか…。 https://t.co/g8CEjm4IuF
根本原因は「Django 側でクエリ取得のためにアクセスしている属性がライブラリ側から消えたため、SQL を取得できなくなっていた」ということでした。
Django 側の対応としては、これまで _last_executed
から取得していたクエリを _executed
から取得するように変更したようです(mysqlclient の PR にもそのやりとりが記載されており、このPRで対応されました)。
結局、プロジェクトAでは mysqlclient のバージョンを 1.4.2.post1 にあげ、SQL が出力されることを確認しました。
ライブラリを使う以上、変更点は注意深く見ておく必要があると改めて感じたお話でした。