コンソールに階層構造付きで呼び出し履歴(トレース)を出してみる。出来るだけダーティーな実装で
階層付きのトレース出力をこのような感じで実装します。
(function(global) { function console_q() { function begin() { console.log(repeat("|", nest) + "+- " + fname + "(" + slice.call(args).join(",") + ")"); } function q() { console.log(repeat("|", nest) + "| " + fname + "(" + slice.call(arguments).join(",") + ")"); } function end() { console.log(repeat("|", nest) + "`- " + fname); return --console.q.nest; } function repeat(str, num) { return Array(num + 1).join(str); } function nickname(fn) { return fn.name || (fn + "").split("(")[0].trim().slice(9); // ) } var args = arguments, fname = nickname(args.callee.caller), slice = Array.prototype.slice, nest = console.q.nest++; begin(); q.valueOf = end; return q; } console.q = console_q console.q.nest = 0; })(this);
使いかたはこんな感じに
function one() { var q = console.q("関数の引数とか"); q("途中経過とか"); two(); -q; // デストラクタ代わり } function two() { var q = console.q("関数の引数とか"); q("途中経過とか"); three(); -q; // デストラクタ代わり } function three() { var q = console.q("関数の引数とか"); q("途中経過とか", "色々だしてみたり", 123); -q; // デストラクタ代わり }
one() を実行すると、
+- one(関数の引数とか) | one(途中経過とか) |+- two(関数の引数とか) || two(途中経過とか) ||+- three(関数の引数とか) ||| three(途中経過とか,色々だしてみたり,123) ||`- three |`- two `- one
とコンソールに階層構造付きで出力されます。
時刻ぐらい出せばいいのにね!
おまけ
13年ほど前にC++で同じようなログ/トレースを実装してたのを思い出して、js で出来るだけ邪悪に実装してみました。
JavaScript にはデストラクタが無いので、
-q; // デストラクタ代わり
のように、デストラクタをわざわざ書かなきゃならないのが面倒ですね。
デストラクタを呼び出すには、-q; としなくても --q; や +q; でもOKです。valueOf が呼ばれればいいので。
C++ で実装する場合は
デストラクタに --nest と ログを吐くコードを書いておけば、スコープアウトで勝手にログがでるので、
らくちんなんです。
C++でマルチスレッドな環境で、この形式のログをスレッド番号付きで出しておくと、
リソース開放漏れや、スレッドが何処で何時死んだのかがログに残るので、
大変分かりやすいログが取れます。
気に入ったら真似するといいですよ~
追記
mofmof.js の console.q の実装は、割とクリーンな感じに。
var q = console.q(関数名); // トレース開始 q(引数とか、トレースに残したい何か); // 何かだすよ q.end(); // 終わり
// console.q function console_q(/* var_args */) { // @param Mix: var_args // @return Function: // @desc: quick trace function begin(fn) { // @param Function/String(= ""): function or function name fnName = (Type.isString(fn) ? fn : fn.nickname()) || "unknown"; console.log("|".repeat(nest) + "+- " + fnName + "(now:" + (+now) + ")"); } function trace(/* var_args */) { // @param Mix: var_args console.log("|".repeat(nest) + "| " + fnName + "[" + Array.toArray(arguments).join(",") + "]"); } function end() { var time = Date.now() - (+now); console.log("|".repeat(nest) + "`- " + fnName + "(time:+" + time + ")"); --console.q.nest; } console_q.nest === void 0 && (console_q.nest = 0); var args = arguments, fnName = "", now = new Date, nest = console.q.nest++; begin(); trace.end = end; return trace; }
function one(arg1, arg2) { var q = console.q("one"); q(arg1, arg2); two(arg1, arg2); q.end(); } function two(arg1, arg2) { var q = console.q("two"); q(arg1, arg2); three(arg1, arg2); q.end(); } function three(arg1, arg2) { var q = console.q("three"); q(arg1, arg2); for (var i = 0; i < 3; ++i) { q("loop", i); } q.end(); }
これを、one("a", "z") として実行すると(↓)こんな感じに。
+- one(now:1326954199430) | one[a,z] |+- two(now:1326954199433) || two[a,z] ||+- three(now:1326954199437) ||| three[a,z] ||| three[loop,0] ||| three[loop,1] ||| three[loop,2] ||`- three(time:+3) |`- two(time:+8) `- one(time:+11)
関数の開始時間(now:...)と、経過時間(time:...)も出すようにしています。
arguments.callee.caller とか valueOf はどこいったのー って感じですね。ハイ