Hi!
My team is developing a service in node. We are experiencing high CPU utilization and are attempting to profile, but are having a hard time getting a sufficient picture of what’s going on. We have experience profiling in various other environments, but this is our first crack at node. We've tried a few different tools (including nodetime.com, which has been useful for some things), and have spent most of our time with the v8 profiler. The main problem is that our viewable results only cover a small portion of the program runtime. More than 80% of the time is spent in libc.so, and that time isn't rolled up by function or caller in the node program. Also, the C++ section, which I would expect to contain events in the v8 interpreter itself, is empty. (Below, I'm including an abbreviated output from the v8 tick processor.) We're aware that the v8 profiling output changes frequently, and we've managed to figure out how to get the right tick processor version that corresponds to the node version we are using. (Our steps are here: https://gist.github.com/kennethgunn/6770664 ) We've seen very similar results with versions of node ranging from v0.8.9 to v0.10.18. Is libc actually responsible for 80+% of the CPU time? If so, how do we roll that up to the the higher level code leading to those calls? Does it sound like we're missing something here, or is there another set of tools we should consider using? Your help is greatly appreciated! -Ken ------ [Shared libraries]: ticks total nonlib name 369080 84.3% 0.0% /lib/x86_64-linux-gnu/libc-2.15.so 45389 10.4% 0.0% /opt/nvm/v0.10.15/bin/node 3624 0.8% 0.0% /lib/x86_64-linux-gnu/libpthread-2.15.so 150 0.0% 0.0% /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.16 94 0.0% 0.0% 7fffeddff000-7fffede00000 68 0.0% 0.0% /lib/x86_64-linux-gnu/libm-2.15.so 23 0.0% 0.0% /lib/x86_64-linux-gnu/librt-2.15.so . . . [JavaScript]: ticks total nonlib name 1185 0.3% 6.1% LazyCompile: BSON.deserialize /mnt/nomic/api/node_modules/mongodb/node_modules/bson/lib/bson/bson.js:1129 544 0.1% 2.8% KeyedLoadIC: A keyed load IC from the snapshot 403 0.1% 2.1% LazyCompile: *Buffer.toString buffer.js:392 363 0.1% 1.9% Stub: CEntryStub 270 0.1% 1.4% LazyCompile: CallSiteGetMethodName native messages.js:8 . . . [C++]: ticks total nonlib name [GC]: ticks total nonlib name 3494 0.8% [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 369080 84.3% /lib/x86_64-linux-gnu/libc-2.15.so 45389 10.4% /opt/nvm/v0.10.15/bin/node 11117 24.5% LazyCompile: *createWriteReq net.js:656 11089 99.7% LazyCompile: *Socket._write net.js:617 11076 99.9% LazyCompile: *Writable.write _stream_writable.js:160 11076 100.0% LazyCompile: *Socket.write net.js:610 8431 76.1% LazyCompile: obj.(anonymous function) /mnt/nomic/api/node_modules/nodetime/lib/core/proxy.js:37 1022 9.2% LazyCompile: *Connection.flush /mnt/nomic/api/node_modules/pg/lib/connection.js:246 1001 9.0% LazyCompile: ~OutgoingMessage.end http.js:855 307 2.8% LazyCompile: *Connection.sync /mnt/nomic/api/node_mod . . . -- -- 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 --- You received this message because you are subscribed to the Google Groups "nodejs" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. For more options, visit https://groups.google.com/groups/opt_out.
