Accounting for time spent using Timeline

170 views
Skip to first unread message

scott....@sap.com

unread,
Oct 3, 2012, 4:57:23 PM10/3/12
to google-chrome-...@googlegroups.com
Hi,

I'm starting to play around with the Timeline in DevTools and I'm kind of blown away by it.  So much useful information packed into one screen.  Truly awesome.

I watched a couple of good tutorials to get up to speed and I've got decent handle on what I'm looking at overall.  But I'm still having some trouble accounting for all of the time spent.  There seem to be gaps where I'm not sure what is happening.

Here's a screen shot from Canary.  It's a very short recording where essentially I click a button and cause about 10,000 SVG circles to move around the screen.  The SVG elements were previously created so it is just setting attributes on existing elements to do its thing.  It is using D3 transitions to drive the process so it hammers on the DOM pretty hard to change the <circle> attributes repeatedly.

The first thing I see is the Event (click) call, which makes sense.  But expanding this line I see that the majority of the time is spent in "Function Call (program)", but it's not clear to me what this actually means.  What is happening when it says "program"?  Then there are a bunch of GC Events but you can see that there are big gaps between the events where nothing is happening -- or, I guess, really it means that the parent node "program" is doing something.  But what?

Next there is a big "Recalculate Style", which is kind of inexplicable to me.  The code location is a spot where all I'm doing is setting a new value into a text box.  I have a feeling that this might be doing something fancy behind the scenes to batch up recalculate style runs because in the Chrome Stable version of this I see thousands of tiny little recalculate style entries (essentially one for each <circle> on which I'm calling getComputedStyle).  These aren't present in Canary so I wonder if they are getting lumped together into one line and the little text box update is being blamed for the lot of them just by luck.

After that there is an "Animation Frame Fired" which again doesn't seem to show me much other than a bunch of GC Events.  The call stack seems to show the location of the RequestAnimationFrame call, not anything to do with the callback.  And, again, the GC Event entries all have big gaps in between them.  What is happening in the middle of these events?

So, overall, I love these tools and I feel like I'm right on the edge of really seeing what is going on internally when my app runs.  But there are some missing pieces here that seem to indicate I'm not getting the complete picture.

Can anybody offer a better interpretation of what I'm seeing here?

Thanks,
scott
Reply all
Reply to author
Forward
0 new messages