intra-martでSQLログを効率よく出力する方法。
intra-martでSQLログを出力する場合ですが、真っ先に思いつくのが製品標準のdatabaseロガーを使う方法です。
ログレベルがデフォルトでoffになっているのでdebugにします。
WEB-INF/conf/log/im_logger_database.xml
こうするだけで以下にSQLログが出るんですけど
WEB-INF/log/platform/database.log
コンソールがやたらと流れるようになります。
10秒もしたら以下の文言でコンソールが埋め尽くされます。
[DEBUG] DB_LOG. - [log.connection.open] コネクション(System/System) がオープンされました。 [DEBUG] DB_LOG. - [log.access.query] クエリーに成功しました。 [INFO] DB_LOG. - [log.transaction.commit] トランザクションがコミットされました。 [DEBUG] DB_LOG. - [log.connection.close] コネクション(System/System) がクローズされました。
DBログのほうにもトランザクションとコネクションが…っていうノイズ入りまくりです。こんなのTRACEでいいような…。
どうやら非同期タスク監視のSQLが1secおきに実行されていているのを拾っているっぽいです。
これではログが流れて効率が悪いです。
im社もこの問題は理解しているっぽく、対処方法が以下のログ仕様書に付録として記載されています。
付録 — ログ仕様書 第8版 2016-12-01 intra-mart Accel Platform
ドキュメントを読めばわかりますが、log4jdbcを使います。
これでノイズのないSQLだけのログが出力できます。
実はこれ、もの凄い便利なことがあって通常、SQLログというとSQLとパラメタが別々に出ると思いますが、こいつはSQLにパラメタが埋め込まれた形で出力されます。
なのでコピペだけでSQLが実行できます。
さらに実行にかかった時間も出るので性能も確認できます。
これはデバッグが捗ります。
以下のような感じで出ます。(ドキュメントより引用)
[INFO] j.sqltiming - select b.menu_group_id from ( SELECT menu_group_id FROM b_m_menu_group_cate_inclusion WHERE category IN ('im_sitemap_pc') ) a inner join b_m_menu_group_b b on a.menu_group_id = b.menu_group_id inner join b_m_menu_b c on b.menu_id = c.menu_id ORDER BY c.sort_number,b.menu_group_id {executed in 43 msec} [INFO] j.sqltiming - SELECT * FROM imaz_resource WHERE resource_id = 'd0b2358a8017b27c11bfacc2e7640f85b47d3f89aeacaaebe3d1c24ba92486be' {executed in 0 msec}
intra-martでSQLログを出す際は、絶対log4jdbcを使ったほうがいいです。
SQLログってアプリを開発する上で結構重要なものだと思いますが、ログ仕様書(タイトなプロジェクトだとこんなの見る余裕がない)しかも付録として記載されていてもったいない感じだったので書いてみました。