Log4js(JavaScriptのログ出力ライブラリ)を改造してJavaScriptのベンチマークができるようにしました

SEの竹村です。

リッチなアプリケーションを作ろうとするあまり、JavaScriptを多用して複雑な処理を組んでいたりするとCPUスペックが 1GHz程度のパソコンでは動作が遅くなってしまう…ということが多々あると思います。

そんな時は、もっと高速にレスポンスが返るように調整したり、実装方法自体を変えてみたりするわけですが、まずはどの部分が重くなっているのかを知るために、またどれくらい改善できたのかを確認するために、コードをベンチマークしてみる必要があります。

JavaScriptのベンチマークを調べてみると、下記のようなツールを見つけました。

▼[javascript][benchmark.js]ベンチマークツール公開
http://d.hatena.ne.jp/amachang/20060906/1157571938

これは、1つの関数単位で速度計測するため、複数の関数の連動について調べたければ、速度計測するためのテストコードを書かねばならない可能性があります。

もっと、PHPのPEARのBenchMarkのように、任意に埋め込んだマーカーのポイント毎に速度計測してくれればベストですよね。

Log4jsを改造して、そのようなベンチマーク計測ができるようにしました。

まずは、『どのようにしたいか』を見ていただきたいので、先ほどのPEAR BenchMarkについて説明します。

▼PEAR BenchMark
http://pear.php.net/package/Benchmark/docs/1.2.6/Benchmark/Benchmark_Timer.html

<?php

require_once 'Benchmark/Timer.php';

$timer = new Benchmark_Timer();
$timer->start();
(処理)
$timer->setMarker('Marker 1');
(処理)
$timer->stop();
$timer->display();
?>

↓このような結果が表示されます。

このように、任意のマーカーを埋め込んで、その間の処理時間が計測できればよい、ということになります。
そこで、Log4jsを利用します。

Log4jsの説明については、下記ページで紹介されているので分かると思います。

▼log4js - JavaScriptログ出力ライブラリ
http://fnya.cocolog-nifty.com/blog/2006/12/log4js_javascri_6be6.html

▼[リンク]AJAXアプリケーションのデバッグ、JavaScriptログ出力、Log4js
http://d.hatena.ne.jp/brazil/20050920/1127212454

Log4jsをそのまま利用するだけでは、ベンチマーク情報は表示されません。そこで、ちょっと改造します。

Log4js.Logger = function(name) {

    // -> add takemura on 2007/04/03:Set startDate and beforeDate

    this.startDate = new Date();

    this.beforeDate = this.startDate;

    // <- add takemura on 2007/04/03:Set startDate and beforeDate

(...)

    debug: function(message) {

        if (this.isDebugEnabled()) {

        // -> modify takemura on 2007/04/03:View process time

        var time  = new Date() - this.startDate;

        var btime = new Date() - this.beforeDate;

        this.beforeDate = new Date();

        this.log(time+'('+btime+"):"+message, Log4js.Level.DEBUG);

        // <- modify takemura on 2007/04/03:View process time

    }

},

使い方は、Log4jsの今までどおりの利用方法で構いません。

log4js = new Log4js('console');

log4js.debug('start');
処理
log4js.debug('Marker 1');
処理
log4js.debug('end');

上記のように記述した場合は、↓このような結果が表示されます。

DEBUG - 2874(2874):start

DEBUG - 2884(10):Marker 1

DEBUG - 9438(6554):end

カッコ内が前回ログ出力した時点からの処理時間(ミリ秒)となります。
この場合は、「Marker 1?endまでの間が重かった」ということが分かりますね。

Log4jsはログレベルを変更することで表示/非表示の管理ができるので、リリース直前までパフォーマンスチューニングを行うことができます。なるべく多くのユーザにリッチなアプリケーションが提供できるようにするためにこういった細かい調整の必要があれば、利用してみてください。

上記で紹介した、ベンチマーク機能付きLog4jsはバージョン0.2ベースを改造したものでしたが、本家では0.3がリリースされているようでした。

▼log4js
http://log4js.sourceforge.net/

このバージョン0.3に対応させたベンチマーク付きLog4jsは、下記からダウンロードできます。

「ダウンロード」
log4js-0.3-addBenchmark.tar.bz2
ライセンスは Apache License, Version 2.0 です。
ファイルをダウンロード

Log4jsの version 0.3 を利用したサンプルは下記参照。

▼ベンチマーク付き Log4js ver.0.3 サンプル
http://staff.ark-web.jp/~takemura/public/js/log4js/log4js-ver0.3-add_benchmark.html