15

Of course, Firebug, Chrome's Web Inspector, Opera's Dragonfly and dynaTrace's AJAX tools for IE have profiling capabilities. However, I haven't found a tool that lets me 'ignore' a library.

To give an example, suppose I have the following pure JS/DOM code:

function foo(node) {
    for (var i = 0; i < node.childNodes.length; i++) {
        node.childNodes[i].innerHTML = 'Test';
    }
}

and a similar bit of code that uses jQuery:

function bar(jqNode) {
    jqNode.children().each(function() {
        $(this).html('Test');
    });
}

(examples aren't exactly great code, please leave them be as that isn't the point)

If you throw both through a JS profiler, you'll find that in the first example, there's just one function where the 'own time' of the function equals the 'total' time spent in the function - as the DOM manipulations get counted as 'own time'.

In the jQuery example, however, all of this is abstracted away into jQuery, which means the 'own time' is minimal and all the time is spent in jQuery.

This makes it very hard to find performance bottlenecks, because the functions with the highest 'own time' are jQuery.fix and jQuery.init and such (which doesn't tell me anything about how well-written (or not) my code is), and the functions with the highest 'total time' are usually too high up the call stack to find out where the actual problem is (if you have one function that calls 10 others, and one takes 'forever', the calling function will have a bigger 'total time' but that won't let you figure out which of the called functions take the longest').

Gijs
  • 5,201
  • 1
  • 27
  • 42
  • Raynos: Profiling code using other libraries will get you the same problem. Writing your own wrappers to account for browser craziness and various other problems libraries would solve for you means you're writing your own library - which still runs into this problem. I don't think your suggestion helps. The example I gave is admittedly skewed in that you of course don't need to use `each`, but easy access of elements in browsers without querySelector(All) will have the same problem, and isn't as to get 'round. – Gijs Dec 14 '11 at 09:08

4 Answers4

4

Filtering out libraries is not what you want and AFAIK no profiler does it the way you want it to. Besides, if your code is badly written because it is abusing library calls, you want to see which library calls it is abusing.

Use the built-in Chrome profiler in "Tree (Top Down)" mode. (Select the mode at the bottom of the Self and Total columns.) In this mode you can see the total time each function takes along with the total time spent in each function that function calls and so on down to the leaf functions that call no other functions. So in your function bar() you will see the total time spent in bar and below that, the total time spent by bar calling each and so forth. (Now with jQuery it can get a bit convoluted, but that's not really the point.)

So if you have one function that calls 10 others, and one takes 'forever', the calling function will have a bigger 'total time' and you figure out which of the called functions take the longest by clicking on the triangle and expanding the 'forever' function and looking at the total time of each of the functions it calls. If 9 take little time and 1 takes forever, then that's the culprit and you keep drilling down until you find the problem.

EDIT: A few more tips on using Chrome's profiler

  • Use "Heavy (Bottom up)" view to find leaf functions that are taking a lot of time. The triangles display who calls them.
  • option-click on a triangle to open the entire tree. Saves lots of clicking through deeply nested call chains.
  • "(program)" refers to the part of the time the profiler was running during which no JavaScript was running. Things like rendering the HTML.

You can do filtering and focusing on a per-function basis. Read the documentation for details on this and more.

Old Pro
  • 24,624
  • 7
  • 58
  • 106
  • 1
    "(Now with jQuery it can get a bit convoluted, but that's not really the point.)" - but that's exactly my point. :-) Chrome's profiler in top-down mode pretends that it spent 53% of the time in 'program' (say what?), and almost all other functions have self time 0%. The max total time is the topmost library function (jQuery event handling). To get to the bit I care about, I have to walk the tree like this: http://www.gijsk.com/temp/profiling.png . Problem is, this function gets called a zillion other times from other parts of that tree. This isn't an effective solution. – Gijs Apr 23 '12 at 10:57
  • (for context, this is code that does static analysis of JS, using AST walking, hence the ridiculous nesting - I care about the speed of my analysis code, not about the speed of the walking code (which I don't really want to change unless it's absolutely necessary)) – Gijs Apr 23 '12 at 11:00
  • @Gijs, obviously your code is complex and what you are interested in is some small part of it, so you can't expect me to understand exactly how to have you focus in on what you want. I can assure you, though, that Chrome's profiler is good enough for you to get the answer. In your image, you see that total time dropped off 5% between `walk` and `walkers.stat`. So the part of the code in `walk` that translates between the call from of `walk` from `MAP` to the call of `walkers.stat` is a place to optimize. Your code in analyze is a trivial amount of time in comparison and need not be changed. – Old Pro Apr 23 '12 at 17:09
  • @Gijs, the situation you describe in your comment is the opposite of the one in the question. If you are worried about the impact of code that gets called from a lot of places, use "Heavy (Bottom Up)" mode. If your function doesn't show up in that list, it's because it's self time is such a small portion of the total time of the profile that it is insignificant, which means it's efficient enough. If you recognize in the list a function that your function calls, you can click on the X button at the bottom of the function list to assign that function's execution time to its callers. – Old Pro Apr 23 '12 at 17:47
  • 1
    I don't think this situation is different. If you look at the profile top-down, it's lost in the tree of library functions. If you look at it bottom-up, it indeed gets lost because it has little 'self' time. However, the function's heaviness stems from its (recursive/repeated) library calls. If you look at the screenshot, you'll see the highlighted function also show up near the top of that tree. :-) Your suggestion about the 'X' button is interesting. Can this be done automatically (on source URL?) and for 'intermediate' functions in the callgraph rather than just leaves? – Gijs Apr 24 '12 at 17:11
  • @Gijs, AFAIK you can not filter out functions automatically. You can filter out any single function and it will be filtered everywhere in the profile. In your imagination, how would you discover that your function is taking so long because it is calling a library function with the wrong options, causing that library function to make many unnecessary function calls that take up a lot of time? Because if your function's self-time is small, that's the only avenue left for significant improvement. – Old Pro Apr 24 '12 at 17:27
  • Basically, I have several analyzing functions which are run for some/all of the nodes in the AST. They recursively call other library fns that explore the AST further. To even begin to figure out what makes it 'slow', I want to know which of those functions have the worst behaviour. Because they all keep calling each other and the library, currently neither 'self' nor 'total' are adequate. Assigning the library time to the 'self' time of their callers, but not the time of any 'own' functions which get called further down, would help, AIUI. – Gijs Apr 24 '12 at 20:04
  • In any case, thank you for taking the time to think along here! The 'X' button seems like what I need, although it'd certainly help if there were a way to include whole files (and have the result persist; I guess right now, if I change something, reload the page and do another profile, I have to manually 'ignore' those functions again...) – Gijs Apr 24 '12 at 20:07
1

Have you tried John Resig's profiler plugin ?

http://ejohn.org/blog/deep-profiling-jquery-apps/

Romain Meresse
  • 3,044
  • 25
  • 29
  • 1
    The links to the actual plugin on that blogpost seem to be dead, and Google isn't turning up any useful alternatives. Also, from the looks of it this plugin lets you see which jQuery methods are taking a long time. I don't care about this particularly - I care about which parts of **my code** run slowly, and want to fix those. If that involves fixing jQuery code, that's a second step. It shouldn't be the first; my code is much more likely to be stupid than jQuery's (inefficient selectors, etc.). – Gijs Dec 12 '11 at 14:58
1

You could try turning profiling on and off in code using console.profile and console.profileEnd. The links are to Firebug documentation, but at least Webkit also supports it. Not sure about IE.

Erik Hesselink
  • 2,420
  • 21
  • 25
  • 1
    This will create separate profiling results, which is pretty useless : I don't know of a way to combine these results, and in a reasonably complex app you enter/exit jQuery orders of magnitude more often than your own functions get called, so there would be *lots* of profiling results. – Gijs Dec 12 '11 at 15:00
1

Using the dynaTrace AJAX Edition, you can exclude a library specified by its URL in the preferences dialog. In the Agent tab, you can give a list of files that should not be traced. So if you list your jquery.js there, you shouldn't see any jquery-related nodes in your PurePaths...

wgottesheim
  • 21
  • 5
  • In fact this does not do what it says on the tin. They still show up, they just get listed as being from the `` file. Browsing the function source code still shows the original jQuery code, though... – Gijs Jan 06 '12 at 10:29
  • Development of dynaTrace AJAX Edition stopped 2014. The version 4.5.0 from 2014 is still available. Last supported Firefox version is 34. https://www.dynatrace.com/topics/ajax-edition/ – Stefan Nov 30 '16 at 12:07