Permalink
Browse files

Fix stack reconstruction. Also add the ability to pause tracing and to

clear the output window.
  • Loading branch information...
1 parent 8869913 commit b4d9c1dc4ef7c2928f2f4a2c4eaef0450f29139e @sfrancisx committed May 22, 2012
Showing with 110 additions and 41 deletions.
  1. +2 −0 README
  2. +64 −16 traceconsole.js
  3. +4 −0 tracer.js
  4. +40 −25 weaver.js
View
2 README
@@ -45,5 +45,7 @@ There are some things to keep in mind:
* The tracer code is wrapped in YUI modules. If you're not using YUI, you'll have to change the wrapping. Other than the wrapping, though, it's self-contained and doesn't rely on YUI.
+* The tracer uses log4js - https://github.com/sfrancisx/log4js.
+
-Steve Francis
sfrancisx@yahoo.com
View
@@ -41,10 +41,8 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
Y.comms.log4js.register("traceconsole",
function(logger, show, name)
{
- var w, doc, output, root, timer, verbose, showStack, tedious, status,
- lastFrame = { depth: 0, idx: 0, created: 1 },
- frames = [ ],
- fnCount = { },
+ var w, doc, output, timer, verbose, showStack, tedious, status, paused, lastFrame, root, frames,
+ // fnCount = { }, // See the comment below about fnCount
/**
* A custom log4js appender for displaying tracer output. This appender
* is incompatible with 'normal' logging. Normal appender expect
@@ -65,10 +63,12 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
*/
notify: function(entry)
{
+ if (paused)
+ return;
+
var frame = entry.msg;
- frame.idx = entry.id;
- frames[frame.idx] = frame;
+ frame.idx = frames.push(frame) - 1;
if (typeof entry.msg != "object")
{
@@ -77,11 +77,15 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
return;
}
- if (!frame.stack)
- {
- fnCount[frame.name] = fnCount[frame.name] || 0;
- fnCount[frame.name]++;
- }
+ // This counts the number of times a particular function gets traced. If tracing
+ // makes the app unbearably slow, uncomment these lines (& the declaration above),
+ // let the tracer run a while, and then break here. Open a console window and
+ // execute something like:
+ // for (name in fnCount) { if (fnCount[name] > 500) console.log(name + ": " + fnCount[name]); }
+ // to see the most commonly traced methods. Add those methods to the weaver's
+ // blacklist.
+ //if (!frame.stack)
+ // fnCount[frame.n || frame.name] = (fnCount[frame.n || frame.name] || 0) + 1;
while (lastFrame.depth > frame.depth - 1)
lastFrame = lastFrame.parent;
@@ -96,6 +100,12 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
clearTimeout(timer);
timer = setTimeout(expand, 100);
}
+
+ if ((frames.length - 1) % 500 == 0)
+ {
+ console.log("updating status to " + (frames.length -1));
+ status.innerHTML = (frames.length - 1) + " methods traced.";
+ }
},
/**
* Show the tracer's output window.
@@ -128,13 +138,16 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
'.expandable > .expandee { margin-left:5px;display:none }' +
'.expandable.expanded > .expandee { display:block }' +
+ '.toolbutton { font-size:90%; margin:2px; float:right; }' +
'</style>' +
'</head>' +
'<body class="fixed" style="padding:0;margin:0;font-size:77%;font-family:tahoma,verdana">' +
'<div id="toolbar">' +
'<input id="showStack" type="checkbox" class="check"></input><label for="showStack">Include Stack</label>' +
'<input id="verbose" type="checkbox" class="check"></input><label for="verbose">Verbose</label>' +
'<input id="tedious" type="checkbox" class="check"></input><label for="tedious">Tedious</label>' +
+ '<label for="pause" style="float:right;margin:3px">Pause</label><input id="pause" type="checkbox" style="float:right" class="check"></input>' +
+ '<button id="clear" class="toolbutton">Clear</button>' +
'</div>' +
'<div class="output">'+
'<div id="frame_0"></div>' +
@@ -156,6 +169,8 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
doc.getElementById("showStack").onclick = refresh;
doc.getElementById("verbose").onclick = update;
doc.getElementById("tedious").onclick = update;
+ doc.getElementById("pause").onclick = pause;
+ doc.getElementById("clear").onclick = clearAndRefresh;
},
/**
* Redraw the output. This method is public, but should
@@ -173,7 +188,7 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
if (output)
{
output.innerHTML = '';
- for (var i = 0; i < frames.length; i++)
+ for (var i = 1; i < frames.length; i++)
{
if (frames[i])
frames[i].created = 0;
@@ -184,14 +199,47 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
},
refresh = a.refresh;
+ clear();
+
logger.show = a.show;
show && a.show();
- root = lastFrame;
-
return a;
/**
+ * Pause tracing.
+ * @method pause
+ * @private
+ */
+ function pause()
+ {
+ paused = doc.getElementById("pause").checked;
+ Y.comms.aop && (Y.comms.aop.paused = paused);
+ }
+
+ /**
+ * Reset the trace console's data
+ * @method clear
+ * @private
+ */
+ function clear()
+ {
+ root = lastFrame = { depth: 0, idx: 0, created: 1 };
+ frames = [ root ];
+ }
+
+ /**
+ * Clear the trace console
+ * @method clearAndRefresh
+ * @private
+ */
+ function clearAndRefresh()
+ {
+ clear();
+ refresh();
+ }
+
+ /**
* Update the output. Used when the verbose/tedious state changes.
* @method update
* @private
@@ -202,7 +250,7 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
tedious = doc.getElementById("tedious").checked;
var frame, el, inner, index,
- i = 0;
+ i = 1;
for (; i < frames.length; i++)
{
@@ -347,7 +395,7 @@ YUI.add('comms-log4js-appenders-traceconsole', function(Y)
if (innerHTML)
el.innerHTML += innerHTML;
- status.innerHTML = frames.length + " methods traced.";
+ status.innerHTML = (frames.length - 1) + " methods traced.";
}
/**
View
@@ -52,6 +52,10 @@ YUI.add('comms-aop-tracer', function(Y)
// and I don't use it. Tell the logger not to do it.
logger.noDate = 1;
+ // Uncomment this line if you have a lot of stuff in the global namespace that
+ // you don't want to weave.
+ //window._$woven$_ = 1;
+
advice.before._$woven$_ = 1;
advice.after._$woven$_ = 1;
View
@@ -81,7 +81,9 @@ YUI.add('comms-aop-weaver', function(Y)
weaveBlacklist = blacklist || weaveBlacklist;
maxWeaveDepth = maxDepth || maxWeaveDepth;
+ inAdvice++;
weave(ns, o, 1);
+ inAdvice--;
for (i = 0; i < all.length; i++)
delete all[i]._$marked$_;
@@ -157,9 +159,15 @@ YUI.add('comms-aop-weaver', function(Y)
*/
function weave(ns, o, depth)
{
- var name, wovenFn, fullName, prop, weaveIt, embedIx, own,
+ var name, wovenFn, fullName, prop, weaveIt, embedIx, own, i,
embedCount = embeds.length;
+ for (i = 0; i < window.frames.length; i++)
+ {
+ if (o == window.frames[i])
+ return;
+ }
+
// if not a DOM element and not the global window object
if (!o.getElementsByTagName && (o != window))
{
@@ -238,7 +246,7 @@ YUI.add('comms-aop-weaver', function(Y)
case 'object':
// guard against null as in JS null is an object
if (prop && (depth < maxWeaveDepth))
- weave(fullName, prop, depth);
+ weave(fullName, prop, depth+1);
break;
}
}
@@ -303,50 +311,57 @@ YUI.add('comms-aop-weaver', function(Y)
* @param {function} fn The method to be advised/instrumented
* @return {function} The advised method
*/
- function aspect(fullName, fn)
+ function aspect(fullName, fn, name)
{
return function()
{
- var retVal, beforeMsg, i, stack, j, s, reporting,
+ var retVal, beforeMsg, i, stack, j, s,
depth = callDepth,
- _this = this,
args = arguments;
- if (inAdvice)
- return fn.apply(_this, args);
+ if (inAdvice || aop.paused)
+ return fn.apply(this, args);
stack = getStack();
+
stack.reverse();
- reporting = i = 0;
- // Call the 'before' advice for non-woven functions we discovered on the stack. Note
- // that the 'after' advice won't be called for these functions.
+ // Call the 'before' advice for non-woven functions we discovered on the stack.
+ // Note that the 'after' advice won't be called for these functions.
+ i = j = 0;
+ if (stack.length)
+ {
+ j = lastStack.length;
+ while (j && (lastStack[j-1].fn != stack[0].fn))
+ j--;
+ }
+
+ lastStack.length = j;
+ stack.push({ fn: fn, name: fullName, args: args, n: name });
+
+ inAdvice++;
+
+ i = j ? 1 : 0;
while (s = stack[i++])
{
- if (reporting || (s.fn != lastStack[j]))
- {
- s.depth = ++callDepth;
+ lastStack[j++] = s;
+ s.depth = j;
+ if (stack[i])
s.stack = 1;
- reporting = 1;
- beforeMsg = advice.before(s);
- }
+ beforeMsg = advice.before(s);
}
- lastStack = stack;
-
// run the before advice
- inAdvice = 1;
- beforeMsg = advice.before({ fn: fn, name: fullName, depth: ++callDepth, args: args });
- inAdvice = 0;
+ inAdvice--;
- retVal = fn.apply(_this, args);
+ retVal = fn.apply(this, args);
// run the after advice(s), if any
- inAdvice = 1;
+ inAdvice++;
advice.after(beforeMsg, retVal);
- inAdvice = 0;
+ inAdvice--;
- // If the function returns an object, weave it, jsut because we can. The fullName
+ // If the function returns an object, weave it, just because we can. The fullName
// here will be wrong - this object probably isn't being attached to 'this'.
// I should probably indicate this somehow.
if (retVal && (typeof retVal == 'object') || (typeof retVal == 'function'))

0 comments on commit b4d9c1d

Please sign in to comment.