O. R. Mapper O. R. Mapper - 5 months ago 30
Javascript Question

How to interpret Chrome's JS profiling timeline?

I have minimized and anonymized the function names/calls in this question (and accordingly retouched the image). The actual names and callstack depth should be of no concern for answering this question.

I am trying to find a bottleneck in a web application by means of Google Chrome's timeline. However, I am not sure how to interpret the data displayed after recording a timeline.

For instance, I am using the following function:

function obj.a = function (x, y) {
console.log('a(' + x + ', ' + y + ')');
return x.getNested().b(y);
};


After profiling it, the flame chart and the event log make it seem as if
console.log
and
b
were invoked more than once by
a
. For instance, the event log looks like this:

event log

Other invocations of
a
appear to (randomly?) feature even more nested invocations of
b
and
log
.

The official documentation such as How to use the timeline tool only provides unhelpful statements such as


When the JS profiler is enabled, your flame chart shows every JavaScript function that was called.


So, how is the JS profiling information displayed om the Timeline panel supposed to be read and interpreted for finding out which function call requires how much time?

Answer

I have created an example where we have three functions that get executed, where the last one, c, calls the first one in a loop.

Example:

function a() {
    console.log("a");
}

function b() {
    console.log("b");
}

function c() {
    for (var i = 0; i < 10000; i++) {
        console.log("c");
        a();
    }
}

a();
b();
c();

The Event Log looks like this:

Events

You can see the three calls a, b, c at the top. The c can be expanded and you will see a load of a calls as you would expect. My understanding for the reason the c calls are repeated several times is due to CPU interrupts. The CPU is given a slice of time to run the JavaScript, it then gets interrupted, and does some other job and then comes back, so the Timeline shows the resuming of the function when the CPU context returns to the JavaScript.

Nested Events

The Call Tree tab should give you a nicer view of the execution times for each function, as per below:

Call Tree

Comments