DBFlute-0.9.5.3ではSQLのログ周りを強化

@DBFlute-0.9.5.3, Java, Eclipse
まだこの記事の時点では0.9.5.3-RC1(ぜひお試し下さい)ですが、
DBFlute-0.9.5.3ではSQLのログ周りを強化しました。
#
# (DBFLUTE-532){Java}:
# Insert文やUpdate文のカラムの順序をDB定義の通りに
#
今までは、HashMapに巻き込まれてランダムになっていました。
DBFluteではInsert文に改行を入れてカラム名と対比しやすい
ようにしてはいますが、
insert into MEMBER (MEMBER_ACCOUNT, UPDATE_DATETIME, ...
 values ('testAccount', '2009-08-03 01:31:20', 'FML', ...
カラム数が多ければ当然見つけるのは大変で、さらに
普段は別にあまり意識しない共通カラムと混じったりすると
なおさら見たいものがなかなか見つからなかったりします。
(一秒とかそう言うレベルの話ですが、それでもディベロッパーには
 ストレスができるだけ掛からない方が良いので)

なので、これをDB定義と同じにしました。
ちなみにこちらUpdate文でも同じ話となります。
insert into MEMBER (MEMBER_NAME, MEMBER_ACCOUNT, ...
 values ('testName', 'testAccount', 'FML', '2009-08-...
DB定義と同じというのはJDBCからDB定義と同じ順序で
メタ情報が取得できることが前提です、一応色々なDBを
ざっと見た限りは大丈夫な感じです。このあと紹介される
全ての似たような話でも同じことです。
#
# (DBFLUTE-531){Java}:
# ConditionBeanでSelect句のカラムの順序をDB定義の通りに
#
今までは、Class.getMethods()のJDKの実装に依存していました。
SUNの実装だとEntityでの定義通り(DB定義の通りと同義)っぽいですが、
MacOSXの実装だとバラバラな感じです。
やはり、DB定義の通りの方が気持ちいいですね。
(DBFluteはメタ情報を保持しているので、無理にEntityの定義から
リフレクションで取得する必要はないのでした)
select dflocal.MEMBER_ID as c1, dflocal.MEMBER_NAME ...
#
# (DBFLUTE-530){Java/C#}:
# ConditionBeanのSQLのログでSelect句を見やすく
#
今までは、From句やWhere句は改行を綺麗に入れて見やすくしてましたが、
Select句はそれに比べればそこまで見る機会は少ないので、それよりは
ログが縦長にならないようにすることを優先していました。
無駄に縦長だとそれはそれでログが非常に見づらくなるからです。
しかし、setupSelectされた関連テーブルの確認がしづらいので、
テーブル単位で改行するようにしました。
これが「縦長にもならないし確認したいことは確認しやすくなる」
くらいのちょうどいい感じかと。
-- select [MEMBER's columns]
--      , [MEMBER_STATUS's columns]
select dflocal.MEMBER_ID as c1, dflocal.MEMBER_NAME ...
     , dfrelation_0.MEMBER_STATUS_CODE as c14, dfrel... 
  from MEMBER dflocal
    left outer join MEMBER_STATUS
 where ...
#
# (DBFLUTE-528){Java}:
# SQL実行時の呼び出し階層ログのリファクタ
#
DBFluteSQL実行時にそのBehaviorを呼び出したクラスと
メソッドと行番号が出力されるということは、
DBFluteを利用されている方ならよくご存知化かと思います。
/================================================= 
                            MemberBhv.selectList() 
                            =====================/
FooPage._post():103 --> ...

select MEMBER_ID, MEMBER_NAME, ...
  from MEMEBR
開発中にログを見る場合に「このSQLはどこのSQLなんだ!?」
って探すことが良くあります。その時Where句を見て判断することも
多いかと思いますが、「どのクラスのどのメソッドの何行目」ってのが
ログに出てれば一番世話ないなというところです。

で、今まではPageクラスの中でメソッドを呼び出している場合、
先頭の呼び出し情報しか表示されなかったので、すぐにディスパッチして
別メソッドでたくさん処理をしている場合は全てのSQLで同じ情報が
表示されていましたが、先頭だけでなく末端も表示するようにしました。
/================================================= 
                            MemberBhv.selectList() 
                            =====================/
FooPage._post():103 -> FooPage.handle():247 -> ...

select MEMBER_ID, MEMBER_NAME, ...
  from MEMEBR
これでとっても具体的にわかりやすくなったでしょう。
ログが見やすくなればなるほど、ディベロッパーがちゃんとログを見て
デバッグする習慣がついてくれればいいなぁと考えています。
また、この機能は「Pageで終わるクラス」と「Actionで終わるクラス」が
対象でしたが、今回「Testで終わるクラス」も対象にしました。
つまり、単体テストで実行したログにテストクラスとテストメソッドの
情報が同じように表示されます。
「ConditionBeanBasicTest.test_basic_Tx():99 -> ...」
単体テストの時は、ArrangeのためのSQL、AssertのためのSQLなど
余計なSQLを多く出力することも多いです。そのとき、この機能で
Actで実行したSQLと区別がしやすくなればと思います。
(Actで実行するSQLも複数だったりしますしね)
また、この機能は「Page/Action/Test」とは独立して、
呼び出し階層として表示されるクラスがあります。
「Service(Impl)で終わるクラス」と「Facade(Impl)で終わるクラス」
です。今回からは「Logic(Impl)で終わるクラス」も追加されます。

もし、PageクラスからLogicを呼び出してBehaviorを呼び出した場合:
/================================================= 
                            MemberBhv.selectList() 
                            =====================/
(略) -> FooPage.handle():247 -> FooLogic.setup():86 -> ...

select MEMBER_ID, MEMBER_NAME, ...
  from MEMEBR

-- ※(略)は「FooPage._post():103」です。
-- このBlogのデザインの都合上、省略してるだけです
このように呼び出しの道筋がわかります。
「Page/Action/Test」と同じように先頭と末端を表示するので、
最大四つの呼び出しメソッドが表示される可能性があります。
内部的には、
「Page/Action/Test」を「Client」
「Service/Facade/Logic」を「ByPass」
と呼んでいます。
また、先頭の呼び出しを「Head」、末端の呼び出しを「Tail」。
なので、この言葉で呼び出し階層の仕様を表現すると:

1. 「Client」の「Head」
2. 「Client」の「Tail」
3. 「ByPass」の「Head」
4. 「ByPass」の「Tail」

という感じになります。
HeadとTailが同じ場合は一つになって、
両方とも存在しない場合は何も表示しない。

もちろん、この機能はログレベルがデバッグときのみ有効です。
そして、パフォーマンスには細心の注意を払っています。
デバッグ時のみとはいえ、便利とはいえ、パフォーマンス劣化
するのはいやですから。(スタックトレースの取得は一回だけ)
また、とてつもなく長いスタックトレースの場合に延々追うことはなく、
探す階層数に制限を決めています。業務的に必須のものではないので、
取れそうにないときは無理はしません(その時は表示されないだけです)。
最後に、すっごい話が飛びますが、自分はEclipseを使うときに
Consoleの位置をちょっとデフォルトの場所から変えています。
デフォルトはこんな感じ(のはず):

で、自分はすぐにこういう風に変えます。

ログはどうしても「日時・スレッド名・ログレベル・呼び出し元」など
必要最低限の情報が表示されますので、横長になりがちです。
(これらはこれらでとても重要なので省略しない方が良いです)
なのでこのようにConsoleを横長にする方がログが圧倒的にみやすいかと。
コンソールが出る場面では「Package Explore」はそんなに縦長
じゃなくてもいいかと思いますし、「Package Explore」を真剣に
使うときは単にConsoleタブは消せば良いし。
(また処理が実行されたときにConsoleタブは自然に復活します)