IEでもFirebugについてくる処理時間計測用のProfileという機能が欲しくて作ってみた。
IE8からはFirebug相当のデバッグツールがついてくるのでいいけど、IE6,IE7あたりでは結構使えるかも。
他のBrowserでも使えるはず。
FirebugのProfileのように勝手に計測してくれるのではなく、計測部分にコードを埋め込まないといけないのはしかたがないと思って欲しい。
以下、ソースとその後に使い方。
/*
================================================================================
Name : profiler
In : [none]
Out : [none]
Note : 処理時間を計測する
--------------------------------------------------------------------------------
Version : Ver1.0.0 | 2009/02/07 | 新規作成
--------------------------------------------------------------------------------
License : MIT license
URL : www.kanasansoft.com
================================================================================
*/
var profiler=(
function(){
var timeRun={};
var resultData={};
var subResultData={};
var startForMain=function(name){
if((name in resultData)&&resultData.hasOwnProperty(name)){
}else{
timeRun[name]=[];
resultData[name]={
"count":0,
"sum":0,
"min":Number.POSITIVE_INFINITY,
"max":Number.NEGATIVE_INFINITY
};
subResultData[name]={};
}
var body={
"time":new Date().getTime(),
"index":timeRun[name].length
};
timeRun[name].push(body);
return getForChain(name,body);
}
var stopForMain=function(name,subname){
if(timeRun[name].length==0){
return false;
}
var timeCur=timeRun[name].pop();
var passed=new Date().getTime()-timeCur.time;
saveResult(name,subname,passed);
}
var stopForChain=function(name,body){
return function(subname){
var index=void(0);
for(var i=Math.min(body.index,timeRun[name].length-1);i>=0;i--){
if(body==timeRun[name][i]){
index=i;
break;
}
}
if(index==void(0)){
return false;
}
var timeCur=timeRun[name].slice(index,index+1)[0];
var passed=new Date().getTime()-timeCur.time;
saveResult(name,subname,passed);
timeRun[name]=timeRun[name].slice(0,index).concat(timeRun[name].slice(index+1));
}
};
var getForChain=function(name,body){
return {
"stop":stopForChain(name,body),
"dummy":function(){return this;}
}
}
var saveResult=function(name,subname,passed){
if(subname){
if((subname in subResultData[name])&&subResultData[name].hasOwnProperty(subname)){
}else{
subResultData[name][subname]={
"count":0,
"sum":0,
"min":Number.POSITIVE_INFINITY,
"max":Number.NEGATIVE_INFINITY
};
}
subResultData[name][subname].count++;
subResultData[name][subname].sum+=passed;
subResultData[name][subname].min=Math.min(subResultData[name][subname].min,passed);
subResultData[name][subname].max=Math.max(subResultData[name][subname].max,passed);
}else{
resultData[name].count++;
resultData[name].sum+=passed;
resultData[name].min=Math.min(resultData[name].min,passed);
resultData[name].max=Math.max(resultData[name].max,passed);
}
}
var result=function(){
var results=[];
results.push(
[
"start name",
"stop name",
"count",
"minimal time(ms)",
"maximum time(ms)",
"total time(ms)",
"average time(ms)"
].join("\t")
);
for(var name in resultData){
if(resultData.hasOwnProperty(name)){
var running=[
"["+name+"]",
"(running)",
timeRun[name].length,
"-",
"-",
"-",
"-"
].join("\t");
var buf={
"count":0,
"sum":0,
"min":Number.POSITIVE_INFINITY,
"max":Number.NEGATIVE_INFINITY
};
var subResults=[];
if(resultData[name].count!=0){
buf.count+=resultData[name].count;
buf.sum+=resultData[name].sum;
buf.min=Math.min(resultData[name].min,buf.min);
buf.max=Math.max(resultData[name].max,buf.max);
subResults.push(
[
"-",
"(no name)",
resultData[name].count,
resultData[name].min,
resultData[name].max,
resultData[name].sum,
resultData[name].sum/resultData[name].count
].join("\t")
);
}
for(var subname in subResultData[name]){
if(subResultData[name].hasOwnProperty(subname)){
buf.count+=subResultData[name][subname].count;
buf.sum+=subResultData[name][subname].sum;
buf.min=Math.min(subResultData[name][subname].min,buf.min);
buf.max=Math.max(subResultData[name][subname].max,buf.max);
subResults.push(
[
"-",
"["+subname+"]",
subResultData[name][subname].count,
subResultData[name][subname].min,
subResultData[name][subname].max,
subResultData[name][subname].sum,
subResultData[name][subname].sum/subResultData[name][subname].count
].join("\t")
);
}
}
results.push(running);
if(buf.count!=0){
results.push(
[
"-",
"(all)",
buf.count,
buf.min,
buf.max,
buf.sum,
buf.sum/buf.count
].join("\t")
);
}
results=results.concat(subResults);
}
}
return results.join("\n");
}
return {
"start":startForMain,
"stop":stopForMain,
"result":result
}
}
)();
関数内の分岐にも対応
関数内を書き変えてまで計測計測するのは抵抗があるかもしれないけど、これは終了判定別に記録するため。
例えば、if文内でreturnを実行して関数を終わらせる場合に重宝するかと思う。
profilerを変数に保存して使う
start実行時に戻り値を変数に入れておけば、stopの時に名前を指定しなくても止める事ができる。
これにより停止順を個別に指定できる。
下の例は交互に実行と停止を行なった場合。
変数を使わなければ(1)は(2)の約3倍の時間が測定されるけど、下の例であれば(1)と(2)はほぼ同じ時間になる。
マトリックス的に使う
以下のようにすると、マトリックスを生成可能。
これはprofilerを変数に保存できる機能と、変数に保持したprofilerのstop処理の引数に終了時の名前を指定できることを応用した例。
処理をメソッドチェーンで
ここからはマニアックな機能。
こんな書き方も可能。
中間処理用にdummyというメソッドがある。
特に一時的な処理や後で削除したい処理を書く時に明示的に書く事もできる。
応用例
なんの役に立つかはわからないけど次のような書き方も可能。
最後に
開始終了処理に名前が指定できる点、変数に保持できる点、メソッドチェーンが可能な点、この三点の機能があるので、ここにあげた方法だけでなくアイディア次第で色々な計測ができると思う。
しかし、処理結果生成の処理がどうも綺麗になっていなくて気持ち悪い。
functionでまとめたい場所も多々ある。
でも、functionを呼ぶのは処理コストが大きいらしい。
計測そのものに時間がかかると、計測結果に影響してしまうのでデータ収集時にはできるだけ複雑な処理をしないようにしている。
その影響でresultメソッド内が複雑になっている。
それでももうちょっとなんとかなかないかと思ってたり...。