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
