コンポーネントのプロファイリング

コンテナで管理しているコンポーネントのプロファイルを取るユーティリティを書いてみました。グローバルインターセプターを使ってさくっと作れます。

• コンテナで管理しているコンポーネントのメソッドを呼び出した回数、所要時間を集計して表示します。
• コンテナで管理しているコンポーネントのみが対象。次のようなオブジェクトは対象にできません。
  • 外部のオブジェクト
  • コンポーネント内で生成しているオブジェクト。
• 仕組みは簡単。グローバルインターセプターでメソッド呼び出しをフックして、集計しているだけ。

サンプル

/**
 * テスト対象の処理
 *  -SubLogicAを2回
 *  -SubLogicBを10回
 * 実行する
 */
function MainLogic() {}
MainLogic.prototype  = {
    toString: function() { return "MainLogic"; },
    run: function() {
        this.subA.run();
        this.subA.run();
        for (var i=0; i < 10; i++ ) {
            this.subB.run();
        }
    }
}
/**MainLogicから呼ばれる処理*/
function SubLogicA() {}
SubLogicA.prototype  = {
    toString: function() { return "logicA"; },
    run: function() {
        var str = "";
        for (var i=0; i < 10000; i++ ) {
            str = "hogehoge" + i ;
        }
    }
}
/**MainLogicから呼ばれる処理*/
function SubLogicB() {}
SubLogicB.prototype  = {
    toString: function() { return "logicB"; },
    run: function() {
        var str = "";
        for (var i=0; i < 5000; i++ ) {
            str = "hogehoge" + i ;
        }
    }
}

// コンテナ
c = new container.Container( function(binder) {

    // プロファイル対象をコンポーネントとして登録する。
    // コンテナで管理されているコンポーネントのAPI呼び出ししかプロファイリングできないので注意。
    binder.bind( MainLogic ).to( "main" ).inject({
        subA: container.component("subA"),
        subB: container.component("subB")
    }) ;
    binder.bind( SubLogicA ).to( "subA" );
    binder.bind( SubLogicB ).to( "subB" );

    // プロファイラインターセプタを適用。
    // toStringはプロファイル適用対象から除外すること。
    // Profiler.interceptor内でコンポーネントのtoStringを呼び出しているので、無限ループにはまる。
    binder.bindInterceptor( Profiler.interceptor,
        container.any(),
        new container.Matcher( /.*/, /toString/ ) );
} );

// メイン処理を実行
c.get("main").run();

// プロファイル結果を表示。
Profiler.instance.show( "stdout" );

実行結果はこちらから

実装

/**
 * プロファイラ
 */
function Profiler() {
    this.result = {};
    this.stack = [];
}
Profiler.prototype = {
    /**
     * メソッド呼び出し開始の通知を受け取る
     * @param {String} name オブジェクト名
     * @param {String} method メソッド名
     */
    begin: function( name, method ) {
        var start = new Date().getTime();
        var id = name + "#" + method;
        this.stack.push( {id:id, start:start} );
    },
    /**
     * メソッド呼び出し終了の通知を受け取る
     */
    end:   function() {
        var data = this.stack.pop();
        var time = new Date().getTime() - data.start;
        if ( !this.result[data.id] ) {
            this.result[data.id] = {
                count: 1,
                total: time
            };
        } else {
            this.result[data.id].count += 1;
            this.result[data.id].total += 1;
        }
    },
    /**
     * 結果を指定したIDのノードに出力する。
     * @param {String} id 出力先ノードのID
     */
    show:  function( id ) {
        var str = "<table border='1px'>";
        str += "<tr>" ;
        str += "<th>オブジェクト#メソッド</th>";
        str += "<th>合計呼び出し時間(msec)</th>";
        str += "<th>呼び出し回数</th>";
        str += "<th>平均呼び出し時間(msec)</th>";
        str += "</tr>";
        for ( var i in this.result ) {
            str += "<tr>" ;
            str += "<td>" + i + "</td>";
            str += "<td>" + this.result[i]['total'] + "</td>";
            str += "<td>" + this.result[i]['count'] + "</td>";
            str += "<td>" + (this.result[i]['total'] / this.result[i]['count']) + "</td>";
            str += "</tr>";
        }
        str += "</table>";
        document.getElementById(id).innerHTML = str;
    }
}
// 唯一のインスタンス
Profiler.instance = new Profiler();

// プロファイルインターセプタ
Profiler.interceptor = function( mi ) {
    try {
        Profiler.instance.begin( mi.getThis().toString(), mi.getMethodName() );
        return mi.proceed();
    } finally {
        Profiler.instance.end();
    }
}