EzJDBCで危険な香りのするSQLを検知する機能！
こんにちは、最近日記からすっかりナリを潜めていた高橋です。
別に誰からも相手にされないからといってスネていた訳ではなく、今度仕事で利用する某社のJavaフレームワークを調査・学習していたため、EzServlet&EzJDBCの開発があまり進まなかっただけです。
そんな私が、今回ご照会するのはEzJDBCで危険な香りがするSQLを検知する機能です。
ところで、危険な香りがするSQLとは、どんなSQLなのでしょうか？
ずばり、SQL応答時間が悪い(遅い)SQLなのです...
SQL応答時間が悪い(遅い)SQLは無条件に危険とは言えないかもしれませんが、危険度が高いSQLであることは間違いありません。
そこで、EzJDBCまたはEzTxを利用してSQLを発行した場合は、SQLの応答時間が、ある一定の閾値(しきい値)を超えるとWarningメッセージを出力する機能を提供します。
閾値（しきい値）はEzTx.propertiesのキー「SQL_RESPONSE_TIME_THRESHOLD_MILLI_SECOND」にミリ秒を設定することで指定します。
では、SQLの応答時間が0.3秒を超えたら危険度が高いSQLとみなして、ワーニングメッセージをSQLログにワーニングメッセージを出力する場合の例を見てみましょう。
EzTx.propertiesで閾値(ミリ秒)の設定を行います。(設定を消すか、値に0以下を設定すると、チェックは行わなくなります)
# SQL応答時間ワーニングメッセージ出力閾値(ミリ秒)
SQL_RESPONSE_TIME_THRESHOLD_MILLI_SECOND = 300
Javaコード
3テーブルを結合しGROUP BYで集約・加算した2つのSQLをUNIONで結合し、最後にORDER BYで並べ変えを指定する。
また、それぞれのSQLの抽出条件の比較値を動的パラメータで指定したコードを実行する。
// 1つ目のSQL
EzJDBC jdbc1 =
selects(CS.name,CS.code,CS.version.sum()).from(CS).join(OD,CI)
.where(CS.name.between("'A", "Z"))
.and(CS.code.ge(0).or(CS.code.le(100)))
.and(OD.created.eq(null))
.groupBy()
.orderBy(CS.name.ASC, CS.code.DESC,CS.version.DESC);
// 2つ目のSQL
EzJDBC jdbc2 =
selects(CS.name,CS.code,CS.version.sum()).from(CS).join(OD,CI)
.where(CS.name.between("'A", "Z"))
.and(CS.code.ge(0).or(CS.code.le(100)))
.and(OD.created.eq(null))
.groupBy();
// UNIONで結合しSQLを発行Listlist = jdbc1.union(jdbc2).find(Customer.class);
上記コードの実行結果のSQLログ
青字のログがSQL応答時間が0.3秒を超えたときに出力されるログです。
赤字について説明します。
1.ログレベル「WARN」で出力されます。
2.設定しきい値が出力されます。今回の例ですと0.3秒(300MS)が、しちい値として出力されます。
3.しきい値を超えたSQLを出力します。
4.3のSQLが発行された時刻をと応答時間を出力します。この情報により、どの処理で呼び出されたSQLかが判別可能になります。赤字以降のログは、考えられる改善策が出力されます。今回は、複数テーブルを結合し、集約：加算してた結果をunionで結合したSQLですので少々複雑です。
このような時は、パラメータマーカーがボトルネックになる場合がありますので、下記の改善策にあるbindメソッドを利用して、比較値をSQL文に直接指定する方法を試した見たいと思います。
[16585653] DEBUG 2010-11-01 16:05:15.609 [main] トランザクションを開始しました
[16585653] DEBUG 2010-11-01 16:05:17.437 [main] コネクションを取得しました（JDBC接続）
[16585653] DEBUG 2010-11-01 16:05:17.656 [main] SELECT CS.NAME,CS.CODE,SUM(CS.VERSION) as VERSION FROM CUSTOMER as CS left join ORDERS as OD on (CS.CODE=OD.CUSTOMER_CODE) left join ORDER_ITEM as OI on (OD.ORDER_NO=OI.ORDER_NO) WHERE CS.NAME between 'A' and 'Z' AND (CS.CODE>=0 OR (CS.CODE<=100)) AND (OD.CREATED is null) GROUP BY CS.NAME,CS.CODE UNION (SELECT CS.NAME,CS.CODE,SUM(CS.VERSION) as VERSION FROM CUSTOMER as CS left join ORDERS as OD on (CS.CODE=OD.CUSTOMER_CODE) left join ORDER_ITEM as OI on (OD.ORDER_NO=OI.ORDER_NO) WHERE CS.NAME between '1' and '9' AND (CS.CODE>=0 OR (CS.CODE<=100)) AND (OD.CREATED is null) GROUP BY CS.NAME,CS.CODE) ORDER BY NAME ASC, CODE DESC, VERSION DESC
[16585653] DEBUG 2010-11-01 16:05:18.078 [main] SQLの実行が完了しました
[16585653] DEBUG 2010-11-01 16:05:18.078 [main] コミットしました
[16585653] DEBUG 2010-11-01 16:05:18.078 [main] コネクションを返却しました
[16585653] DEBUG 2010-11-01 16:05:18.078 [main] トランザクションを終了しました
[16585653] WARN 2010-11-01 16:05:18.421 [main] SQLの応答時間の警告 ...
- -
下記のSQLの応答時間がしきい値(300ミリ秒)を超えました。
対象となるSQL文 : SELECT CS.NAME,CS.CODE,SUM(CS.VERSION) as VERSION FROM CUSTOMER as CS left join ORDERS as OD on (CS.CODE=OD.CUSTOMER_CODE) left join ORDER_ITEM as OI on (OD.ORDER_NO=OI.ORDER_NO) WHERE CS.NAME between 'A' and 'Z' AND (CS.CODE>=0 OR (CS.CODE<=100)) AND (OD.CREATED is null) GROUP BY CS.NAME,CS.CODE UNION (SELECT CS.NAME,CS.CODE,SUM(CS.VERSION) as VERSION FROM CUSTOMER as CS left join ORDERS as OD on (CS.CODE=OD.CUSTOMER_CODE) left join ORDER_ITEM as OI on (OD.ORDER_NO=OI.ORDER_NO) WHERE CS.NAME between 'A' and 'Z' AND (CS.CODE>=0 OR (CS.CODE<=100)) AND (OD.CREATED is null) GROUP BY CS.NAME,CS.CODE) ORDER BY NAME ASC, CODE DESC, VERSION DESC
SQLが発行された時間は、「2010-11-01 16:05:17.656」です。SQLの実行時間は、「422ミリ秒」です。
- -
【考えられる改善策】
1.SQLのチューニングを行う。
・SUBQUERY, JOIN, UNIONを利用している場合は、SQLを見直すことにより改善する場合もあります。
・SUBSTR等の関数を利用している場合はレスポンスが極端に低下する場合があります。一度関数を排除したSQLでレスポンスを調査してください。
・ORDER BYの指定がレスポンスを悪化させている場合があります。昇順、降順の見直しが可能か検討してください。
・上記SQLをCSE等のSQLツールで実行してレスポンスタイムを計測してみてください。レスポンスが良かった場合はパラメータマーカー(?)の利用をやめ比較値をSQL文に埋め込事によりレスポンスが改善されると思われます。
EzJDBCを利用している場合はbindメソッドを呼び出して下さい。bindメソッドを呼び出すと比較値をSQLに埋め込んだSQLを実行します。
注意：EzJDBC以外で、SQLに比較値を埋め込む場合はSQLインジェクションが起こらない様に細心の注意を払ってください。
・Viewやindexの作成を検討してみてください
2.RDBのチューニングを行う。
・DBAに相談のうえチューニングを検討して下さい。
Javaコード
抽出条件の比較値をSQL文に埋め込むbindメソッドを設定します。
// 1つ目のSQL
EzJDBC jdbc1 =
selects(CS.name,CS.code,CS.version.sum()).from(CS).join(OD,CI)
.bind()
.where(CS.name.between("'A", "Z"))
.and(CS.code.ge(0).or(CS.code.le(100)))
.and(OD.created.eq(null))
.groupBy()
.orderBy(CS.name.ASC, CS.code.DESC,CS.version.DESC);
// 2つ目のSQL
EzJDBC jdbc2 =
selects(CS.name,CS.code,CS.version.sum()).from(CS).join(OD,CI)
.bind()
.where(CS.name.between("'A", "Z"))
.and(CS.code.ge(0).or(CS.code.le(100)))
.and(OD.created.eq(null))
.groupBy();
// UNIONで結合しSQLを発行Listlist = jdbc1.union(jdbc2).find(Customer.class);
上記コードの実行結果のSQLログ
[16585653] DEBUG 2010-11-01 16:19:24.468 [main] トランザクションを開始しました
[16585653] DEBUG 2010-11-01 16:19:24.484 [main] コネクションを取得しました（JDBC接続）
[16585653] DEBUG 2010-11-01 16:19:24.484 [main] SELECT CS.NAME,CS.CODE,SUM(CS.VERSION) as VERSION FROM CUSTOMER as CS left join ORDERS as OD on (CS.CODE=OD.CUSTOMER_CODE) left join ORDER_ITEM as OI on (OD.ORDER_NO=OI.ORDER_NO) WHERE CS.NAME between ''A' and 'Z' AND (CS.CODE>=0 OR (CS.CODE<=100)) AND (OD.CREATED is null) GROUP BY CS.NAME,CS.CODE UNION (SELECT CS.NAME,CS.CODE,SUM(CS.VERSION) as VERSION FROM CUSTOMER as CS left join ORDERS as OD on (CS.CODE=OD.CUSTOMER_CODE) left join ORDER_ITEM as OI on (OD.ORDER_NO=OI.ORDER_NO) WHERE CS.NAME between '1' and '9' AND (CS.CODE>=0 OR (CS.CODE<=100)) AND (OD.CREATED is null) GROUP BY CS.NAME,CS.CODE) ORDER BY NAME ASC, CODE DESC, VERSION DESC
[16585653] DEBUG 2010-11-01 16:19:24.625 [main] SQLの実行が完了しました
[16585653] DEBUG 2010-11-01 16:19:24.625 [main] コミットしました
[16585653] DEBUG 2010-11-01 16:19:24.625 [main] コネクションを返却しました
[16585653] DEBUG 2010-11-01 16:19:24.625 [main] トランザクションを終了しました
赤字を参照してください。赤字の差がSQLの応答時間になります。
発行時間が「16:19:24.484」で、完了時間が「16:19:24.625 」になりますから、
SQL応答時間は「141ミリ秒」となります。
改善前は「422ミリ秒」でしたから、かなり改善されましたね（＾＾）
このように危険度の高いSQLを開発段階から潰すことが可能になるのが、EzJDBCなのです....（￣0￣）b
