SQLAlchemyで実行されているSQLを取得する。

SQLAlchemyを使ってるんだが、深刻な性能劣化を発生させてしまった。（個人的に運用してるシステムなので、勤めてる会社とその取引先には何ら影響ないです。）

結果的に、次のとおりクエリを修正した。ありえない凡ミスだった。

（修正前）
TableA.query.filter(TableA.customer_id==customerid, TableA.item_id==itemid, TableB.tenant_id==current_user.tenant_id).all()

（修正後）
TableA.query.filter(TableA.customer_id==customerid, TableA.item_id==itemid, TableA.tenant_id==current_user.tenant_id).all()

この場合に、どんなSQLが実行されているのかを調べてみることにした。


SQLを標準出力するように変更。
import logging
logging.basicConfig()
logging.getLogger('sqlalchemy.engine').setLevel(logging.INFO)

結果は次のとおり。
（修正前）
SELECT hoge, foo, bar
FROM TableA, TableB
WHERE TableA.customer_id = %(customer_id_1)s AND TableA.item_id = %(item_id_1)s AND TableA.youbi = %(youbi_1)s AND TableB.tenant_id = %(tenant_id_1)s

（修正後）
SELECT hoge, foo, bar
FROM TableA
WHERE TableA.customer_id = %(customer_id_1)s AND TableA.item_id = %(item_id_1)s AND TableA.youbi = %(youbi_1)s AND TableA.tenant_id = %(tenant_id_1)s

from句に並べられ、結合なしのSQLが実行されるようだ。
明示的な joinメソッドのない こういう書き方は、実行時エラーでいいんじゃないかと思う。

今回このクエリの役割は、TableAの結果セットの有無のみを必要とするものだったため、TableAにレコードがなければTableBにあっても結果なし なのでこれまで問題とならなかった。

とはいえ、TableBだけで約80万件のレコードがあったのに、これまで体感できるほどの遅さはなく、今回倍の160万件になったところで顕著な遅さがあったので、DB側のパフォーマンスチューニングしか頭になく、解決までむちゃくちゃ時間を要した。
だからといって、ORマッパーは「どんなSQLが実行されているかわからないからダメ」とするのは危険思想だと思うし、設計が美しければ困らないと思うよね。複雑なデータ集計をする帳票とかは別として。