> I feel like the bold line is interesting, and I'm tempted to interpret it as > "fibo() takes 76.5% of the whole CPU", but it's not so simple.
Please read the comment about the profile: Note: percentage shows a share of a particular caller in the total amount of its parent calls. In any case with with statistical profiler "function Foo takes X ticks out of Y ticks recorded total" should be read as "profiler looked at the program Y times and in X times he saw function Foo near the top of the stack". Statistical profiler results do not translate into information about event loop blocking or CPU cycles spent by functions. -- Vyacheslav Egorov On Wed, Sep 12, 2012 at 9:50 AM, Nicolas Chambrier <[email protected]> wrote: > I'll show you what I've done to train until now, so you may better > understand what I'm looking for in case I'm not very clear ^^ > > > So I wrote a basic script: > > function hello() { > console.log('.'); > } > > function fibo(n, cb) { > if (n === 0) { > process.nextTick(cb.bind(null, 0)); > } else if (n === 1) { > process.nextTick(cb.bind(null, 1)); > } else { > var n1, n2; > process.nextTick(fibo.bind(null, n-1, function(n){ n1 = n; next(); })); > process.nextTick(fibo.bind(null, n-2, function(n){ n2 = n; next(); })); > function next() { > if (typeof n1 === 'undefined' || typeof n2 === 'undefined') { > return; > } > process.nextTick(cb.bind(null, n1+n2)); > } > } > } > > var interval = setInterval(hello, 100); > > fibo(24, function (n) { > clearInterval(interval); > console.log(n); > }); > > It produces following output, where I can see how the event loop is blocked, > and the whole point is to detect who is blocking it (here it's obviously > fibo() but I train for less obvious cases ;)) > > $ time node fibo.js > ] 9:43 > . > . > . > . > . > 46368 > node fibo.js 0,95s user 0,06s system 99% cpu 1,021 total > > nprof produces the following output: > > Statistical profiling result from v8.log, (914 ticks, 0 unaccounted, 0 > excluded). > … > [Bottom up (heavy) profile]: > Note: percentage shows a share of a particular caller in the total > amount of its parent calls. > Callers occupying less than 2.0% are not shown. > > ticks parent name > 741 81.1% /usr/local/bin/node > 187 25.2% LazyCompile: bind native v8natives.js:1456 > 143 76.5% LazyCompile: *fibo /home/nchambrier/Bureau/fibo.js:5 > 143 100.0% Function: ~d native v8natives.js:1480 > 142 99.3% LazyCompile: > *startup.processNextTick.process._tickCallback node.js:185 > 44 23.5% Function: ~next /home/nchambrier/Bureau/fibo.js:14 > 30 68.2% Function: ~process.nextTick.fibo.bind.n2 > /home/nchambrier/Bureau/fibo.js:12 > 30 100.0% Function: ~d native v8natives.js:1480 > 30 100.0% LazyCompile: > *startup.processNextTick.process._tickCallback node.js:185 > 14 31.8% Function: ~<anonymous> > /home/nchambrier/Bureau/fibo.js:13 > 14 100.0% Function: ~d native v8natives.js:1480 > 14 100.0% LazyCompile: > *startup.processNextTick.process._tickCallback node.js:185 > … > > I feel like the bold line is interesting, and I'm tempted to interpret it as > "fibo() takes 76.5% of the whole CPU", but it's not so simple. > > I'll give another try to valgrind, just in case. > > > > Le mercredi 12 septembre 2012 09:35:39 UTC+2, Nicolas Chambrier a écrit : >> >> Thanks for your answers. nprof and node-tick-processor have worked >> properly and I could retrieve information from v8.log. Now I just have to >> learn how to use it, it's not as obvious as I could imagine: still no >> function name for example :( I've made a dumb script with a fibo + other >> functions, and I can't see how to make the profiler tell me "fibo() is >> taking all your CPU". If you have any good resources to learn that, I'd be >> glad ;) >> >> Thanks too for the "look" module, I'll give a try it sounds really >> interesting. >> >> I only profiled PHP and Java apps until now, and outputs are very clear, >> maybe this difficulty is generic to C++ apps ? >> >> >> >> >> Le mercredi 12 septembre 2012 02:45:04 UTC+2, Andrey a écrit : >>> >>> Try node-tick-processor to read your v8.log - >>> https://github.com/sidorares/node-tick >>> >>> On Wednesday, 12 September 2012 02:39:26 UTC+10, Nicolas Chambrier wrote: >>>> >>>> Hello, >>>> >>>> I'm desperately trying to profile my application, like I used to do with >>>> other languages where I could output some file I could pass to kcachegrind >>>> which would show me when and where the runtime executed my code. >>>> >>>> I'm running Ubuntu or Debian VM, whatever I've tried several methods: >>>> >>>> Using dtrace on SmartOS: OK I can run dtrace, but I'm absolutely lost on >>>> SmartOS and I need many bricks like Redis and MongoDB I'm not sure how to >>>> install properly (I've compiled everything, which was a pita). Plus I'm not >>>> a sysadmin, which makes me waste ages each time I need to configure >>>> anything. Not forgetting the most recent provided zone (node-1.3.3) >>>> includes >>>> node v0.6.8. Dafuq ? >>>> Using node --prof seemed very promising: simple, everything is embedded, >>>> cool :) I can generate a v8.log, OK. But then when I run >>>> "deps/v8/tools/linux-tick-processor" on it, I get no output, just an exit >>>> code 126. No idea what it means, I couldn't find information about this :( >>>> Using valgrind I can output a callgrind file I can then use with >>>> kcachegrind. It's cool and I get real values, I can practically see the >>>> call >>>> chain, but I can't see my real function names. Instead I get some >>>> hexadecimal names, v8:: and node:: internals. That makes it quite useless >>>> for me :( >>>> nodetime is great, but I'd really like a tool that doesn't rely on >>>> external service. Even if I finally stick with this solution, I need to >>>> have >>>> an alternative. >>>> >>>> >>>> Does someone know where error 126 comes from in linux-tick-processor ? >>>> >>>> Does what I'm looking for only exist: a profiler that would output stack >>>> and durations with the actual function names ? And easy to use on Linux x] >>>> >>>> >>>> Thanks a lot for all the information you can provide! I really want to >>>> get through that this time ;) > > -- > Job Board: http://jobs.nodejs.org/ > Posting guidelines: > https://github.com/joyent/node/wiki/Mailing-List-Posting-Guidelines > You received this message because you are subscribed to the Google > Groups "nodejs" group. > To post to this group, send email to [email protected] > To unsubscribe from this group, send email to > [email protected] > For more options, visit this group at > http://groups.google.com/group/nodejs?hl=en?hl=en -- Job Board: http://jobs.nodejs.org/ Posting guidelines: https://github.com/joyent/node/wiki/Mailing-List-Posting-Guidelines You received this message because you are subscribed to the Google Groups "nodejs" group. To post to this group, send email to [email protected] To unsubscribe from this group, send email to [email protected] For more options, visit this group at http://groups.google.com/group/nodejs?hl=en?hl=en
