Skip to content

Instantly share code, notes, and snippets.

@drocco007

drocco007/example.html

Last active August 29, 2015 14:13
Show Gist options
  • Save drocco007/9bf469617bd09123c68c to your computer and use it in GitHub Desktop.
Save drocco007/9bf469617bd09123c68c to your computer and use it in GitHub Desktop.
Download ZIP
Raw
example.html
<!DOCTYPE html>
<html lang="en">
<head>
<meta charset="UTF-8">
<script src="https://cdnjs.cloudflare.com/ajax/libs/underscore.js/1.7.0/underscore-min.js"></script>
<script src="profile.js"></script>
</head>
<body>
<pre id="output"></pre>
<script>
function bar() {
profile_tool.start("bar", "starting");
profile_tool.log("not much happening yet");
for(var i = 1; i < 1000000; i++) Math.sqrt(Math.random());
profile_tool.log("did some work");
profile_tool.log(true);
}
function foo() {
profile_tool.start("foo", "starting");
for(var i = 1; i < 1000000; i++) Math.sqrt(Math.random());
profile_tool.log("did some work")
for(var i = 1; i < 2000000; i++) Math.sqrt(Math.random());
profile_tool.log("got a bigger hammer");
bar();
profile_tool.log("called bar()");
profile_tool.log(true);
}
foo();
document.getElementById("output").innerHTML = profile_tool.as_csv();
</script>
</body>
</html>
Raw
example_output.txt
message,duration,start,end
starting foo,0,1421458778651,1421458778651
. did some work foo,60,1421458778651,1421458778711
. got a bigger hammer foo,129,1421458778711,1421458778840
. starting bar,0,1421458778841,1421458778841
.. not much happening yet bar,0,1421458778841,1421458778841
.. did some work bar,61,1421458778841,1421458778902
. finish bar,61,1421458778841,1421458778902
. called bar() foo,62,1421458778840,1421458778902
finish foo,251,1421458778651,1421458778902
Raw
profile.js
/**
* Simple JavaScript function profiler
*/
window.profile_tool = {
entries: [],
time_stack: [],
/**
* Start a new subtimer, typically used at the top of a function.
*
* @param {String} label a description for this block, e.g. the method
* name
* @param {String} message (optional) an initial log message
*/
start: function(label, message) {
var now = Date.now();
label = label || "";
this.time_stack.push({
time: now,
last: now,
label: label
});
if (message)
this.log(message, false, -1);
},
format_entry: function(entry) {
return [
entry.message,
entry.duration,
entry.start,
entry.end,
].join(",");
},
/**
* Log a point of interest in a function, preserving the duration since the
* previous call to log() or start(), start and end timestamps, and a log
* message including the call stack depth relative to the outermost
* function using the profile_tool.
*
* @param {String} message (optional) message indicating the location
* inside the function for later reference
* @param {Boolean} pop_time (optional) if true, indicates the end of
* the current logging block
* @param {Int} depth_adjust (optional, internal use) adjust the call
* stack depth
*/
log: function(message, pop_time, depth_adjust) {
var now = Date.now(),
use_last;
if (this.time_stack.length == 0)
this.start();
if (!message || _.isBoolean(message)) {
depth_adjust = pop_time;
pop_time = message || false;
message = "finish";
}
use_last = !pop_time;
depth_adjust = depth_adjust || 0;
var get_time = pop_time ? function(a) { return a.pop(); } : _.last,
time = get_time(this.time_stack),
// http://stackoverflow.com/a/202627
depth = new Array(this.time_stack.length + depth_adjust + 1).join("."),
start = use_last ? time.last : time.time;
this.entries.push({
message: [depth, message, time.label].join(" ").trim(),
start: start,
end: now,
duration: now - start,
});
if (use_last)
time.last = now;
},
/**
* Return the captured log entries as CSV-formatted data.
*/
as_csv: function() {
var results = [];
results.push(["message", "duration", "start", "end"].join(","));
_.each(this.entries, function(entry) {
results.push(this.format_entry(entry));
}, this);
return results.join("\n");
}
};
Raw
profile.rst

Simple JavaScript function profiler

I'm sure there are about 6,427 bajillion ways to do this, but here is a simple JavaScript function profiler that I found helpful when pinpointing some performance bottlenecks. The cool thing about this tool is that the profiling is specific to exactly the places in the code that you're interested in, meaning you don't have to sift through profile information for a bunch of functions you don't care about.

Start each function you want to profile with

profile_tool.start("my function name or whatever", "starting");

and end with

profile_tool.log(true)

which will produce a profile time for the entire function:

. finish bar,61,1421458778841,1421458778902

This line tells us that the total runtime for bar is 61 ms (the label is independent of the function and can be whatever you want at whatever granularity you want).

Within a function, additional calls to log

profile.log("is that previous line my problem?")

will be reported relative to the previous call to log() or start():

.. not much happening yet bar,0,1421458778841,1421458778841
.. did some work bar,61,1421458778841,1421458778902

Here we can see that the expensive operation within bar() is whatever appears between these two call to log.

Requires Underscore, because I'm lazy. If anyone really cares, I can remove that requirement.

Typical usage

  1. Include the JavaScript in your page

  2. Wire up your functions

    function foo() {
    profile_tool.start("foo", "starting");

    // blah

    profile_tool.log("did some work");

    // blah

    profile_tool.log("did some more work");

    // blah

    profile_tool.log(true)
}

  3. Copy the results to the clipboard: in the console:

    > copy(profile_tool.as_csv())

  4. Paste into your favorite spreadsheet or dataframe

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment