雑記帳 2009年 6月第1週

2009/06/01 Mon.

何てこった。「LynnfieldとP55は9月1日になった」らしい。TDPが95Wだから様子見なんだけど、まさか先送りとは。
もともとは7月に登場する予定」だったので、夏になったら買い替えかと思ってたのに、またもや肩透かしを食った感じ。
低消費電力版LynnfieldでTDP65Wになるだろうが、これは来年第一四半期予定だし、今のマシンは今年の夏を越せるのか?
おかげで、Q9550sあたりで買い換えてしまおうかと悩む。「価格.comの最安値」で33,740円だけど、Quadの必要性にも悩む。
DTMに動画編集と画像編集とかを考えればQ9550sは考慮対象だけど、それらの使用時間比率的にどうなのかな。
E8400あたりにすれば15,000円近く浮くけど、次に買うマシンは最低でも3年くらいは使い続けていく予定だし。
Lynnfieldの2.66GHz版は$196の予定だけど、これがHT非対応なのも悩む。2.80GHzになると$284にも跳ね上がるし。
2.80GHz版の低消費電力版が出るとすれば$400は超えるだろうし、今のうちに枯れてきたP45+ICH10あたりで組んじゃう?
Core i7も920で考えたけど、「Lynnfield登場でCore i7 920は販売終了」するんじゃ、普及も情報も望めない感じがするし。
さすがにアッパーミドルからハイエンド向けのCore i7だと、低消費電力版の登場はまず見込めないと考えていいのかな。
自分は冷却関連の知識に弱いから、TDP95Wとかだと日常の使用においても不安だし。やっぱりQ9550sで組んじゃうかなー。

2009/06/02 Tue.

slf4j」を使ってみようと思い、とりあえず適当なソースを書いて見る。使用したjarはslf4j-api-1.5.6.jarのみ。
余計なCommons LoggingやLog4jのライブラリは一切使用しないで、本当にslf4jだけを使ってログを吐いてみる。

package slf4j.test01;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Test {
    private static Logger logger = LoggerFactory.getLogger(Test.class);

    public static void main(String[] args) {
        if (logger.isTraceEnabled()) {
            logger.trace("Trace : Hello, world.");
        }
        if (logger.isDebugEnabled()) {
            logger.debug("Debug : Hello, world.");
        }
        if (logger.isInfoEnabled()) {
            logger.info("Info : Hello, world.");
        }
        if (logger.isWarnEnabled()) {
            logger.warn("Warn : Hello, world.");
        }
        if (logger.isErrorEnabled()) {
            logger.error("Error : Hello, world.");
        }
    }
}

とりあえずさっさとログを吐く確認だけをしたかっただけなのに、いきなりNoClassDefFoundErrorが出てくれました。

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
java.lang.NoClassDefFoundError: org/slf4j/impl/StaticLoggerBinder
    at org.slf4j.LoggerFactory.getSingleton(LoggerFactory.java:189)
    at org.slf4j.LoggerFactory.bind(LoggerFactory.java:112)
    at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:105)
    at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:235)
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:208)
    at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:221)
    at slf4j.test01.Test.<clinit>(Test.java:7)
Exception in thread "main"

org.slf4j.impl.StaticLoggerBinderはslf4j-simple-1.5.6.jarに入っているので、これを追加して再実行してみる。

0 [main] INFO slf4j.test01.Test - Info : Hello, world.
0 [main] WARN slf4j.test01.Test - Warn : Hello, world.
0 [main] ERROR slf4j.test01.Test - Error : Hello, world.

とりあえず出力の確認はできた。しかし、Eclipse上のコンソールでは赤文字で出力されてる。標準エラー出力?
で、一体何の設定を使ってINFO以上のログレベルの出力になっているんだ?Commons Loggingみたいな動きになるのか?
JREのlibの下のlogging.propertiesを読むのかと思いきや、試しにそこの設定をFINESTにしてもINFO以上しか出ない。
VM引数に-Djava.util.logging.config.fileでJREのlibの下のlogging.propertiesを指定しても、結果は変わらず。
Commons Loggingとは微妙に違うのか?つーか、何の機能を使ってコンソールにログを吐いてんの?
slf4j-simple-1.5.6.jarを覗いてみると、org.slf4j.impl.SimpleLoggerなんてのがあった。これを使ってるんだろう。
で、ファイルに吐いたりコンソールに吐いたり、ログレベルを個別に設定するにはどうすればいいんだ。
Commons Loggingはlog4jやAvalonが無ければJDK標準APIを使うようになってるけど、そもそもslf4jはどうなってるんだ。
SimpleLoggerのソースを覗いたら、isTraceEnabled()isDebugEnabled()が常にfalseを返すようになってた。
private void log()は常に標準エラー出力に吐くようになってるし。SimpleLoggerのJavaDocには以下のような記述が。

A simple (and direct) implementation that logs messages of level
INFO or higher on the console (<code>System.err<code>).

slf4jでログを吐く際にSimpleLoggerを使っている以上は、必ずINFO以上のレベルを標準エラー出力に吐きますよってことか。
一応はslf4j単体だけでも、最低限は動かすことは可能ってことね。ログレベルの設定はSimpleLoggerを使う以上は無理だと。
バインダを使ってlog4jやlogbackなどの実際の出力を実装した機能を使用する形に切り替えてやらないとNGってことなのかな。
つーワケで、「logback」の0.9.15を入手してみる。ファイルサイズはおよそ11.5MBで、早速解凍して中身を拝見。
ソースもドキュメントも入っているせいか、ヘボいマシンじゃ解凍だけでも時間食う。まともなマシンをくれ。
解凍したらaccess、core、classicというjarがあるが、どれを使えというのだ。「解説」はあるけど、全部読む気は起きない。
ここ」によると、やっぱりcommons-logging.propertiesみたいな設定は無いみたい。ブリッジによって実装を切り替えるとか。
logbackメモ」の内容を色々読んでおき、先ほどのテストコードを修正してみる。logbackのjarは2つ追加する必要があった。
logback-classic-0.9.15.jarは内部でlogback-core-0.9.15.jarを参照しているので、追加した上でコンパイルして実行。

package slf4j.test01;

import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.Logger;

public class Test {
    public static void main(String[] args) {
        Logger logger = (Logger)LoggerFactory.getLogger(Test.class);
        if (logger.isTraceEnabled()) {
            logger.trace("Trace : Hello, world.");
        }
        if (logger.isDebugEnabled()) {
            logger.debug("Debug : Hello, world.");
        }
        if (logger.isInfoEnabled()) {
            logger.info("Info : Hello, world.");
        }
        if (logger.isWarnEnabled()) {
            logger.warn("Warn : Hello, world.");
        }
        if (logger.isErrorEnabled()) {
            logger.error("Error : Hello, world.");
        }
    }
}

……ありゃ?ClassCastExceptionが出た。トレースを見ると、org.slf4j.impl.SimpleLoggerという記述が出てきている。
ああ、logbackのLoggerじゃなくてslf4jのLoggerになっちゃったのか。ライブラリのslf4j-simple-1.5.6.jarを除外して再実行。
んん?変じゃね?キャスト先はch.qos.logback.classic.Loggerだし、何でいきなりorg.slf4j.impl.SimpleLoggerが出てくるの?
org.slf4j.impl.SimpleLoggerはスーパークラスのスーパークラスにorg.slf4j.Loggerがある。ここまでは問題無い。
LoggerFactory#getLogger()が返すのはorg.slf4j.Loggerで、これをch.qos.logback.classic.Loggerにキャスト、と。
org.slf4j.Loggerinterfaceなので、クラスパス上にあった実装クラスのorg.slf4j.impl.SimpleLoggerを返してしまったのか?
LoggerFactory#getLogger(Test.class).getClass().getName()を試すと、org.slf4j.impl.SimpleLoggerが返ってきた。
うーん、一応は思っている通りのエラーってことでいいのかな。胡散臭いにも程がある。とりあえずエラーを直したい。
ライブラリの読み込み順は、slf4jのapi、simple、logbackのclassic、coreとなっていて、この状態からsimpleを消すと動いた。

16:47:53.002 [main] DEBUG slf4j.test01.Test - Debug : Hello, world.
16:47:53.012 [main] INFO  slf4j.test01.Test - Info : Hello, world.
16:47:53.012 [main] WARN  slf4j.test01.Test - Warn : Hello, world.
16:47:53.012 [main] ERROR slf4j.test01.Test - Error : Hello, world.

おおう、やっと出てきてくれた。とりあえずデフォルト状態だとコンソールへの標準出力のみになるみたいだ。
この状態でLoggerFactory#getLogger(Test.class).getClass().getName()を試したらch.qos.logback.classic.Loggerになった!
logbackメモ」によると、デフォルトはDEBUGからERRORまでの全てのログをコンソールに出力する設定になると書いてある。
で、Traceはどうやって出すんだ?つーか、まずは設定ファイルの書き方から覚えないと話にならなさそうだな。
設定関連は時間かかりそうなので放置、明日にでもやろう。ログの出力メソッドを色々見てたら、面白そうな使い方があった。

package slf4j.test01;

import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.Logger;

public class Test {
    public static void main(String[] args) {
        Logger logger = (Logger)LoggerFactory.getLogger(Test.class);
        if (logger.isInfoEnabled()) {
            logger.info("arg1:{}, arg2:{}, arg3:{}", new String[]{"value1", "value2", "value3"});
        }
    }
}
17:14:34.521 [main] INFO  slf4j.test01.Test - arg1:value1, arg2:value2, arg3:value3

おお、こういう使い方もできるんだ。そういや前にいたプロジェクトでもこんな感じのログ出力をやってた気がする。
そこではlog4jを使ってたんだけど、log4jでこういう書き方もできたんだっけか?Commons Loggingは使ってたっけな?
自分が気付いてなかっただけで、実はslf4jも使ってたのか?つーか、使ってるライブラリを抑えてないとかダメすぎだろ自分。

2009/06/03 Wed.

昨日のslf4jとlogbackでのClassCastExceptionが気になってしょうがなかったので、少しだけど調べてみた。

JUDEとかでまともにクラス図を書くのはメンドいんで、Excelで適当に。なるほど、こういう造りになってたんですか。
それにしても、logbackのLoggerは外のライブラリ(slf4j)のLoggerを実装する形になってるとは。面白い設計ですね。

で、今日はlogbackの設定ファイルの記述に関して軽く勉強。「Log4j徹底解説」の中の「ココ」を参照しました。
というか、このサイトの情報量が凄い。しかも面白い。しかも為になる。未熟者の自分にとっては嬉しい限りだ。
肝心のlogbackの設定ファイルは、logback.xmlという名前でクラスパス上に置いておけば勝手に適用されるらしい。
参考というか丸写しというか、とりあえずlogback.xmlを作成してからクラスパス上に置く。こんなのを書いてみた。

<?xml version="1.0" encoding="UTF-8" ?>
<configuration debug="true">
    <!-- コンソールへの出力設定 -->
    <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
        <Target>System.out</Target>
        <layout class="ch.qos.logback.classic.PatternLayout">
            <!--
            %c, %lo, %logger : カテゴリ名(%c{n}とすると、下からnまで表示)
                slf4j.test01.Test
            %C, %class : ログを生成したクラス名(%c{n}とすると、下からnまで表示)
                slf4j.test01.Test
            %d, %date : 日付指定(日付フォーマットを指定、未指定はyyyy-MM-dd HH:mm:ss,SSS形式)
                2009/06/03 11:14:31.040
            %F, %file : Javaソースファイル名
                Test.java
            %L, %line : Javaソースファイル上の行番号
                11
            %M, %method : Javaソースファイル上のメソッド名
                main
            %m, %msg, %message : ログメッセージ
                Trace : Hello, world.
            %p, %le, %level : ログレベル
                TRACE
            %n : 改行コードを生成
            -->
            <!--
            2009/06/03 11:23:42.125 [INFO ]  slf4j.test01.Test.main(16) Info : Hello, world.
            -->
            <Pattern>%date{yyyy/MM/dd HH:mm:ss.SSS} [%-5p] %C.%M\(%line\) %m%n</Pattern>
        </layout>
    </appender>

    <!-- ファイルへの出力設定 -->
    <appender name="file" class="ch.qos.logback.core.FileAppender">
        <file>log/logback.log</file>
        <append>true</append>
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%date{yyyy/MM/dd HH:mm:ss.SSS} [%-5p] %C.%M\(%line\) %m%n</Pattern>
        </layout>
    </appender>

    <!-- 出力するパッケージを設定 -->
    <!-- クラス名を含めないパッケージを設定すると、パッケージ以下のクラスに対して共通設定 -->
    <!-- レベル設定はoff, error, warn, info, debug, trace, all -->
    <logger name="slf4j.test01.Test" level="info">
        <appender-ref ref="stdout">
        <appender-ref ref="file">
    </logger>

    <!-- ルートロガー(デフォルトロガー)のレベルを設定 -->
    <!-- レベル設定はoff, error, warn, info, debug, trace, all -->
    <root level="info">
        <appender-ref ref="stdout">
        <appender-ref ref="file">
    </root>
</configuration>

一応はこれで動いたんだけど、何だかおかしい。何故かログが二重に出力される。一体何が起こってるんだ?
パッケージ・クラス別とルートのログレベル設定を疑ったけど、設定を色々変えても一回のログ出力で二重に出る。
で、これを書いてる最中に思いついたんだけど、slf4jのSimpleLoggerとlogbackのLoggerが一緒に動いてたりするのか?
ちょっと今は試せないんだけど、明日あたりに調べてみよう。logback入れた後にslf4jのsimpleのjarを外してなかったし。
logbackの情報を色々見ていると、「log4jとlogbackのパフォーマンス比較」なんてのを発見。やっぱりlogbackは速いんだ。

帰りに「合格Javaテキスト―JavaプログラマSJC‐P310‐055対応」なんてのを購入。2,800円ちょい。真面目に覚えよう。
ぶっちゃけGenericsについてはかなり弱い。「Java総称型メモ」や「- Java Generics概説」あたりを熟読してます。
単にList<String>Map<String, String>みたいな型限定の使い方くらいは当然してますが、Map<K, V>とかが理解してない。
後はThreadRunnableとかもいい加減しっかりと抑えておきたいので、数年ぶりに学習用テキストなんて買ってしまった。
あわよくば「SJC-P」合格とかも狙っちゃいたいし。7年目にして資格が皆無ってのも、何だか先行きが不安になるしね。

2009/06/04 Thu.

昨日のlogback.xmlを使って、ログが二重に出る現象を調べてみた。元のソースは一昨日の2つ目のJavaソースです。
あ、そうそう。slf4jのsimpleの方は既に外してあったみたいです。つーか、SimpleLoggerが原因のはずが無いじゃん。
あれはINFO以上しかログに吐かないし、そもそも出力先が標準エラー出力で固定になってる。何で気付かなかったかな。

public void callAppenders(LoggingEvent event) {
    int writes = 0;
    for (Logger l = this; l != null; l = l.parent) {
        writes += l.appendLoopOnAppenders(event);
        if (!l.additive) {
            break;
        }
    }
    if (writes == 0) {
        loggerContext.noAppenderDefinedWarning(this);
    }
}

ch.qos.logback.classic.LoggercallAppenders()の中のfor文が4回動く模様。appendLoopOnAppenders()でログが出る。
for文の初期化箇所のLogger lを見ていると、指定した出力パッケージを順に昇っていき、最後にrootで出力しているみたい。
昨日のlogback.xmlだと、slf4j.test01.Test、slf4j.test01、slf4j、rootの順番で出力しようとしているのがわかった。
最初のslf4j.test01.Testでログを出したら、slf4j.test01、slf4jではログを出していない。だけどrootで再度出力される。
xml上の記述でクラス・パッケージ別指定とrootの設定の順番を入れ替えてみたけど、当然のごとく結果は変わりません。
似たような現象を起こした人はいないものかと色々探してみたけど、該当する情報は一切無し。俺だけかよ。
logback.xmlのconfigureのdebugをtrueにして動かしても、何も警告の類とかは出ないし。一体何が起こってんだ?

途中で諦めて、昨日買ったテキストで勉強。うーん、意外に知らないことが多い。2の補数とか見たの何年ぶりだろう。
2の補数と符号ビットを使って、8ビットで-1を表現すると11111111、-7だと11111001になるけど、負数の計算がメンドい。
0以上ならば1, 2, 4, 8, 16, 32, 64, 128とかでビットを立てて計算していけるけど、負数の簡単な計算方法は無いのかな。

2009/06/05 Fri.

いきなり飛ばして資格勉強なんかしても、長期に渡ってモチベーションが続くはずが無いとわかってるので、今日はお休み。
んで、今日はカバレッジ試験に手を付けようということで「djUnit」に手を付けることに。JUnitとDBUnitと合わせて使いたい。
ダウンロード」のページから、Eclipse 3.2用のpluginを落とす。バージョンは0.8.4の最新版を使っておくことに。
Eclipse上でjarを取り込んで、適当にテストケースを書いて動かしてみたけど、ビューのdiUnit Coverage Reportに何も出ない。
プロジェクトのプロパティでdjUnitの項目があるけど、大して設定する項目も無い。いきなりヘンなトコで突っかかるな。
あれこれ弄り回しているうちに、何故か突然レポートが出るようになった。ん?何を触ったんだっけか。よくわからん。
野村総研のオープンソースドキュメント」が非常に役に立ちます。これの11番にJUnitとdjUnitの解説のPDFがある。
サンプルも書かれていたのでコピって色々動かしてみたけど、載ってるソースとは別にpropertiesを作る必要がある。
Message_ja.propertiesとLogConfig_ja.propertiesを、以下のように作成する。

TestID=TestMessage
Appender=sample.util.SysteOutAppender

最低限この記述が無いと動かない。ってか、サンプルとして載せるなら、Javaソース以外も載せてくれりゃいいのに。
で、これら二つのファイルをsample.utilに置く。うーん、ResourceBundleなんて滅多に使わないから微妙に手間かかった。
試験対象クラスの%branchを100%にしても、そのクラスがstaticメソッドしか持たなかったら、%lineは100%にならないんだな。
コンストラクタなんてまず呼ばないだろうし。しょうがないので、無意味にnewして%lineも100%になることを確認した。
途中で思ったんだけど。djUnit用テストソースってDJUnitTastCaseを継承するじゃん、JUnit4系の記述はできないの?
試しに@BeforeClass@AfterClass@Before@Afterを付けたメソッドを書いてみたけど、どれも動いてくれないみたい。
これはメモ。テスト用クラスのコンストラクタは、デフォルトコンストラクタとStringが1つのコンストラクタを書いてsuper()する。

2009/06/06 Sat.

一日中DTMばっかり。マシンがヘボいせいか、再生中にかなりドロップアウトが起きる。まともなマシンが欲しいです。