Using user mark to analyze performance of your JavaScript code

When working on some advanced JavaScript code like a 3d engine, you may ask yourself what you can optimize and how many time do you spend in some specific pieces of code.

Feel free to ping me on Twitter (@deltakosh) if you want to discuss about this article!

Can’t wait to see what this article is about? Watch out this video:

The first idea that comes to mind is obviously the integrated profiler you can find using F12 tools.

Please note that with the new F12 tools that we shipped with Windows 10 Technical preview, profiler is now part of the UI responsiveness window (I really like the new design by the way…):

Let’s see other options that can give you more insights about how your code is performing.

console.time

You just have to call console.time() and console.timeEnd() around the piece of code you want to evaluate. The result is a string in your console displaying the time elapsed between time and timeEnd.

This is pretty basic and can be easily emulated but I found this function really straightforward to use.

Even more interesting, you can specify a string to get a label for your measurement.

This is for instance what I did for Babylon.js:

console.time("Active meshes evaluation");
this._evaluateActiveMeshes();
console.timeEnd("Active meshes evaluation");

This kind of code can be found around all major features and then, when performance logging is enabled, you can get really great info:

You must be warned that rendering text into the console can consume CPU power

Even if this function is not per se a standard function, the browser compatibility is pretty great. Chrome, Firefox, IE, Opera and Safari support it.

performance object

If you want something more visual, you can use the performance object as well (W3C recommendation / Can I Use?). Among others interesting features to help you measure a web page performance, you can find a function called mark that can emit an user mark.

An user mark is the association of a name with a time value. You can measure portions of code with this API in order to get precise values. You can find a great article about this API by Aurelio de Rosa on Sitepoint.

The idea today is to use this API to visualize specific user marks on the UI Responsiveness screen:

This tool allows you to capture a session and analyze how CPU is used:

We can then zoom on a specific frame by selecting an entry called “Animation frame callback” and right-clicking on it to select “filter to event”.

The selected frame will be filtered then:

Thanks to the new F12 tool, you can then switch to JavaScript call stacks to get more details about what happened during this event:

The main problem here is that it is not easy to get how code is dispatched during the event.

And this is where user marks enter the game (Go Hawks !). We can add our own markers and then be able to decompose a frame and see which feature is the more expensive and so on.

performance.mark("Begin of something…just now!");

Furthermore, when you create your own framework, it is super handy to be able to instrument your code with measurements:

performance.mark("Active meshes evaluation-Begin");
this._evaluateActiveMeshes();
performance.mark("Active meshes evaluation-End");
performance.measure("Active meshes evaluation", "Active meshes evaluation-Begin", "Active meshes evaluation-End");

Let’s see what you can get with babylon.jsbabylon.js for instance with the “V8” scene:

You can ask babylon.js to emit user marks and measures for you by using the debug layer:

Then, using UI responsiveness analyzer, you can get this screen:

You can see that user marks are display on top of the event itself (the orange triangles) as well as segments for every measure:

This is then super easy to determine that, for instance, [Render targets] and [Main render] phases are the most expensive.

The complete code used by babylon.js to allow users to measure performance of various features is the following:

Tools._StartUserMark = function (counterName, condition) {
    if (typeof condition === "undefined") { condition = true; }
    if (!condition || !Tools._performance.mark) {
        return;
    }
    Tools._performance.mark(counterName + "-Begin");
};

Tools._EndUserMark = function (counterName, condition) {
    if (typeof condition === "undefined") { condition = true; }
    if (!condition || !Tools._performance.mark) {
        return;
    }
    Tools._performance.mark(counterName + "-End");
    Tools._performance.measure(counterName, counterName + "-Begin", counterName + "-End");
};

Tools._StartPerformanceConsole = function (counterName, condition) {
    if (typeof condition === "undefined") { condition = true; }
    if (!condition) {
        return;
    }

    Tools._StartUserMark(counterName, condition);

    if (console.time) {
        console.time(counterName);
    }
};

Tools._EndPerformanceConsole = function (counterName, condition) {
    if (typeof condition === "undefined") { condition = true; }
    if (!condition) {
        return;
    }

    Tools._EndUserMark(counterName, condition);

    if (console.time) {
        console.timeEnd(counterName);
    }
};

Thanks to F12 tools and user marks you can now get a great dashboard about how different pieces of your code are working together.