2014年6月11日水曜日

【GAE】初級実装編 ログハンドリング

株式会社ジェニシス 技術開発事業部の遠藤 太志郎(Tacy)です。

只今、クラウド基盤「Google App Engine(以下、GAE)」の連載しています。

本日から「初級実装編」と称しまして、実際にモノを作って行きましょう。
机上で調査するより、実際に作った方がずっと高精度な解析が出来ますからね。

アカウント作成


さて、根本的に「GAEってどうやって始めるの?」という点につきましては、過去の連載をご覧下さい。

  1. 【GAE】Google App Engine 始めに
  2. 【GAE】スタート編1 アカウント作成
  3. 【GAE】スタート編2 アプリケーション作成
  4. 【GAE】スタート編3 Googleプラグイン&SDK取得
  5. 【GAE】スタート編4 Slim3導入

初級実装編では実装から入ります。

最初はログから

GAE開発に限らず、プロジェクトというのは最初が一番肝心です。

何にも無いクリーンな所から色々なライブラリを導入して、クラス設計して、DBのコネクションやトランザクション……など、
最初はやることが多過ぎてどこから着手したら良いか迷う所です。

その点、私の場合は習慣的にログハンドリングを最初に行うことが多いです。

今回はGAEのログ出力機能を確認してみましょう。

java.util.logging.Logger VS log4j

Javaのログハンドリングライブラリは、世の中はlog4jが主流になっていると思いますが、
GAEはJava標準のログハンドリング機能である「java.util.logging.Logger」を使用します。

ここで早くもGAEの特性が出現しました。

私は今まで、いくつかの現場を回っておりますものの、
ログハンドリングはほぼ100%に近い確率でlog4jを使用していました。

ふと気になって調べてみたいのですが、このlog4jの支配力の正体は、どうも純然たる伝統というのが真相のようです。

log4jというのは私が社会人になる前から存在している非常に古い伝統のライブラリで、
それに対してJava標準のjava.util.loggingは後になって作られたそうです。

機能的にもlog4jの方が高機能ですし、欠点と言えばjarファイルをimportしなければいけないということくらい。

あえて後発のjava.util.loggingに乗り換える必要も無いので、大概はlog4jを使っているのでしょう。
私も相当に長い間、「ログとはlog4jのことだ」くらいの気分でいました。

それくらい強力なシェアを誇るlog4jですが、GAEの場合はJava標準に準拠したのでしょうね。
java.util.loggingを使用するのが基本です。

一応、log4jに拘りのある人はlog4jをimportして使用することも出来るのですが、それをやるとGAEの機能をフル活用出来ません。
詳細については以下に続きます。

ログを出力してみる

では、さっそくログを出してみましょう。

まず、slim3プロジェクトを作成すると最初から「logging.properties」というファイルがあります。
これがログレベルを設定するファイルですので、以下のようにログ全出力にします。

.level = ALL

次に、以下のようなログ出力だけの機能を作りまして、これをデプロイし、アクセスしてみます。

public class IndexController extends Controller {

    /** logger */
    private Logger logger = Logger.getLogger(IndexController.class.getName());

    @Override
    public Navigation run() throws Exception {

        logger.finest("finest");
        logger.finer("finer");
        logger.fine("fine");
        logger.info("info");
        logger.warning("warning");
        logger.severe("severe");


        return forward("index.jsp");
    }
}

出力されたログを確認します。
ログと言えば普通はテキストファイルですが、GAEの場合は管理コンソールから閲覧出来ます。

その画像が以下。


なるほど。
つまり、GAEは以下4段階でログレベルを設定してくれるわけです。


  • D:デバッグ。fine、finer、finestの3つ
  • I:インフォ:infoに相当
  • W:ワーニング。warningに相当
  • E:エラー。severeに相当。


管理コンソールの機能により、「エラーだけを表示」のようなフィルタリングも可能です。

ちょっと戸惑うのが、「fine、finer、finest」は全部デバッグレベルとして一纏めにされる点ですが、
これも少し落ち着いて整理すれば簡単な話です。

GAE管理レベルとしては、確かに「fine、finer、finest」は全部同じデバッグレベルです。

しかし、「logging.properties」の設定では、これら3種も切り分けられますので、
「fineは見たいけど、finer、finestは不要」という場合は、logging.propertiesにfineと書いてデプロイすれば良いのです。

この辺りを細かく制御して管理するか、「いっそのことfiner、finestは封印する」かは、その時の判断ですね。

簡単なアプリであれば封印策を取った方がシンプルで良いかと思います。

そして、ここでlog4jの欠点が。
log4jを無理に導入すると、全部INFOログとして扱われます。

せっかくGAEに備わっているログレベルフィルタリング機能が使えなくなってしまいますので、
ここは素直にjava.util.logging.Loggerを使用して下さい。

フォーマット

ログのフォーマットですが、ローカル環境では「フォーマッター」を指定することで自由なフォーマットでログを出力出来ますが、
GAE環境で動かす時はGAEに搭載されたフォーマットしか使用することは出来ません。

なので、必ず上記のようなデザインのログが出力されます。
日付のフォーマットをちょっと変えたいとか、そういうことは出来ないのです。

一方、開発用のローカル環境のログは自分でフォーマットしないと読み辛いですので、
以下のように自分でフォーマットロジックを書いて対応します。

logging.propertiesに以下記述を追加して、フォーマッタークラスを指定します。

java.util.logging.ConsoleHandler.formatter=jp.co.net.genesis.common.LogFormatter

フォーマッタークラスは以下のように記述。

public class LogFormatter extends Formatter {

    /** 時間のフォーマット */
    private static final SimpleDateFormat sdf = new SimpleDateFormat(
        "yyyy-MM-dd HH:mm:ss.SSS");

    /*
     * (非 Javadoc)
     *
     * @see java.util.logging.Formatter#format(java.util.logging.LogRecord)
     */
    @Override
    public String format(LogRecord argLogRecord) {

        StringBuffer bul = new StringBuffer();

        bul.append(sdf.format(new Date(argLogRecord.getMillis())));
        bul.append(" ");

        if (argLogRecord.getLevel() == Level.FINEST) {
            bul.append("FINEST");
        } else if (argLogRecord.getLevel() == Level.FINER) {
            bul.append("FINER ");
        } else if (argLogRecord.getLevel() == Level.FINE) {
            bul.append("FINE  ");
        } else if (argLogRecord.getLevel() == Level.CONFIG) {
            bul.append("CONFIG");
        } else if (argLogRecord.getLevel() == Level.INFO) {
            bul.append("INFO  ");
        } else if (argLogRecord.getLevel() == Level.WARNING) {
            bul.append("WARN  ");
        } else if (argLogRecord.getLevel() == Level.SEVERE) {
            bul.append("SEVERE");
        } else {
            bul.append(Integer.toString(argLogRecord.getLevel().intValue()));
            bul.append("   ");
        }

        bul.append(" ");
        bul.append(argLogRecord.getLoggerName());
        bul.append(" - ");
        bul.append(argLogRecord.getMessage());
        bul.append("\n");

        // 例外がある場合に出力
        Throwable e = argLogRecord.getThrown();
        if (e != null) {
            bul.append(e.getClass().getName());
            bul.append(": ");
            bul.append(e.getMessage());
            bul.append("\n");
            StackTraceElement[] errs = e.getStackTrace();
            for (StackTraceElement s : errs) {
                bul.append("\t");
                bul.append(s.toString());
                bul.append("\n");
            }
        }

        return bul.toString();
    }

}

ローカル環境での挙動は普通のjava.util.logging.Loggerと大差ありません。
標準的なスキルで実現可能ですので、開発者の好みで事由にログフォーマットを記述して下さい。


終わりに

これにてログハンドリングは完了です。

しかし、「ネット上でログを見る」というのは便利な機能ですね。
いつでも自由にログをチェック出来ますから、保守を非常に効率的に行えます。

引き続き、アプリの構築を継続していきます。

0 件のコメント:

コメントを投稿