[nodejs] Profiling problem, is 91% of ticks in libc 'normal'.

[nodejs] Profiling problem, is 91% of ticks in libc 'normal'.

	Chris Dew
	Oct 4, 2012 at 4:22 pm

I'm starting to have a speed problem with a production NodeJS application
(20-100% cpu usage).

I've run it with --prof and used node-tick-processor.

Is 91% of ticks in libc 'normal'?

Thanks,

Chris.

P.S. is there a way to show the 'unaccounted' ticks? I expect it needs to
be told where to find the source of the app.

Statistical profiling result from node, (121509 ticks, 7342 unaccounted, 0
excluded).

  [Unknown]:
    ticks total nonlib name
    7342 6.0%

  [Shared libraries]:
    ticks total nonlib name
   111345 91.6% 0.0% /lib/libc-2.12.1.so
     248 0.2% 0.0% /lib/libpthread-2.12.1.so
      19 0.0% 0.0% /lib/libm-2.12.1.so
      19 0.0% 0.0% /lib/libcrypto.so.0.9.8
       2 0.0% 0.0% ffffffffff600000-ffffffffff601000
       2 0.0% 0.0% 7fff735ff000-7fff73600000
       1 0.0% 0.0% /usr/lib/libstdc++.so.6.0.14
       1 0.0% 0.0% /lib/libssl.so.0.9.8

  [JavaScript]:
    ticks total nonlib name
    1628 1.3% 16.5% LazyCompile: *Socket._write net.js:470
    1391 1.1% 14.1% LazyCompile: *parse native json.js:55
    1196 1.0% 12.1% LazyCompile: ~BasicSerializeObject native
json.js:244
     372 0.3% 3.8% LazyCompile: stringify native json.js:307
     280 0.2% 2.8% LazyCompile: FILTER_KEY native runtime.js:399
     266 0.2% 2.7% LazyCompile: TxnInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/txnInPeriodLRS.js:35
     260 0.2% 2.6% LazyCompile: *formatProperty util.js:298
     221 0.2% 2.2% Function: formatValue util.js:153
     208 0.2% 2.1% Function: formatPrimitive util.js:249
     206 0.2% 2.1% LazyCompile: *GetOwnProperty native
v8natives.js:649
     138 0.1% 1.4% LazyCompile: *indexOf native string.js:115
     118 0.1% 1.2% LazyCompile: Join native array.js:119
     112 0.1% 1.1% Stub: CEntryStub
     107 0.1% 1.1% LazyCompile: *FromPropertyDescriptor native
v8natives.js:385
     103 0.1% 1.0% LazyCompile: *keys native v8natives.js:347
      88 0.1% 0.9% LazyCompile: *BasicSerializeArray native
json.js:181
      86 0.1% 0.9% LazyCompile: ConvertDescriptorArrayToDescriptor
native v8natives.js:593
      86 0.1% 0.9% Function: ~Buffer buffer.js:210
      82 0.1% 0.8% LazyCompile: PropertyDescriptor native
v8natives.js:494
      81 0.1% 0.8% LazyCompile: *EventEmitter.emit events.js:40
      79 0.1% 0.8% Function: ~Buffer.write buffer.js:323
      72 0.1% 0.7% Function: ~EventEmitter.emit events.js:40
      62 0.1% 0.6% Stub: StringAddStub {3}
      60 0.0% 0.6% LazyCompile: resultDelta
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/resultdelta.js:7
      60 0.0% 0.6% LazyCompile: *RegExpExecNoTests native
regexp.js:156
      56 0.0% 0.6% LazyCompile: *indexOf native array.js:1122
      50 0.0% 0.5% Stub: NumberToStringStub
      49 0.0% 0.5% KeyedLoadIC: A keyed load IC from the snapshot
      49 0.0% 0.5% Function: exports.format util.js:23
      45 0.0% 0.5% LazyCompile: *map native array.js:1094
      39 0.0% 0.4% LazyCompile: *BuildResultFromMatchInfo native
regexp.js:126
      39 0.0% 0.4% Builtin: A builtin from the snapshot {2}
      38 0.0% 0.4% Stub: CompareICStub {3}
      38 0.0% 0.4% Function: ~ondata stream.js:36
      38 0.0% 0.4% Builtin: A builtin from the snapshot {3}
      37 0.0% 0.4% LazyCompile: *match native string.js:179
      36 0.0% 0.4% Stub: RegExpExecStub
      33 0.0% 0.3% LazyCompile: hasOwnProperty native v8natives.js:264
      29 0.0% 0.3% Stub: CompareStub
      27 0.0% 0.3% LazyCompile: ~keys native v8natives.js:347
      25 0.0% 0.3% Stub: ToBooleanStub
      24 0.0% 0.2% LazyCompile: VirtualLRS.checkDups
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:219
      24 0.0% 0.2% LazyCompile: ToString native runtime.js:560
      23 0.0% 0.2% Stub: SubStringStub
      23 0.0% 0.2% Builtin: A builtin from the snapshot
      22 0.0% 0.2% LazyCompile: *isRegExp util.js:387
      21 0.0% 0.2% LazyCompile: *formatArray util.js:278
      21 0.0% 0.2% LazyCompile: *VirtualAggregatingLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:53
      20 0.0% 0.2% LazyCompile: ~parse native json.js:55
      20 0.0% 0.2% LazyCompile: ~join native array.js:399
      20 0.0% 0.2% LazyCompile: MdipSuccessesInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesInPeriodLRS.js:45
      20 0.0% 0.2% LazyCompile: *isError util.js:399
      20 0.0% 0.2% LazyCompile: *LocalConnectionByNameLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:43
      19 0.0% 0.2% LazyCompile: ~indexOf native string.js:115
      19 0.0% 0.2% LazyCompile: STRING_ADD_LEFT native runtime.js:183
      19 0.0% 0.2% LazyCompile: $Array.get_ native v8natives.js:558
      18 0.0% 0.2% LazyCompile: Lev.actions
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/levenshtein.js:52
      18 0.0% 0.2% LazyCompile: *UseSparseVariant native array.js:111
      18 0.0% 0.2% LazyCompile: *NativeModule.compile node.js:541
      17 0.0% 0.2% LazyCompile: *parserOnHeadersComplete http.js:48
      16 0.0% 0.2% Stub: CompareICStub {1}
      16 0.0% 0.2% LazyCompile: ToObject native runtime.js:577
      16 0.0% 0.2% LazyCompile: IsDataDescriptor native
v8natives.js:367
      16 0.0% 0.2% LazyCompile: *Socket.write net.js:431
      15 0.0% 0.2% Stub: KeyedLoadElementStub
      15 0.0% 0.2% LazyCompile: *reduce native array.js:1242
      15 0.0% 0.2% LazyCompile: *allocPool buffer.js:281
      14 0.0% 0.1% LazyCompile: toString native v8natives.js:238
      14 0.0% 0.1% Builtin: A builtin from the snapshot {5}
      13 0.0% 0.1% Stub: RegExpConstructResultStub
      13 0.0% 0.1% LazyCompile: b native string.js:36
      13 0.0% 0.1% LazyCompile: Logger.log
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/logger.js:72
      13 0.0% 0.1% LazyCompile: *VirtualLRS.order
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:279
      12 0.0% 0.1% LazyCompile: VirtualLRS.emitDeltas
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:234
      12 0.0% 0.1% LazyCompile: *socket.ondata http.js:1467
      12 0.0% 0.1% LazyCompile: *exports.toArray
/home/chris/CDRReportServer/tags/1.1.0/node_modules/socket.io/lib/util.js:18
      12 0.0% 0.1% Function: ~<anonymous> util.js:359
      12 0.0% 0.1% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sock.js:21
      12 0.0% 0.1% Builtin: A builtin from the snapshot {1}
      11 0.0% 0.1% LazyCompile: *getOwnPropertyDescriptor native
v8natives.js:870
      11 0.0% 0.1% LazyCompile: *VirtualLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:86
      11 0.0% 0.1% LazyCompile: *Manager.checkRequest
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/manager.js:897
      10 0.0% 0.1% LazyCompile: ~BasicSerializeArray native
json.js:181
      10 0.0% 0.1% LazyCompile: *isArray util.js:380
      10 0.0% 0.1% LazyCompile: *exports.active timers.js:143
      10 0.0% 0.1% LazyCompile: *$Array.enumerable_ native
v8natives.js:528
      10 0.0% 0.1% LazyCompile: $Array.writable_ native
v8natives.js:538
      10 0.0% 0.1% Function: ~formatValue util.js:153
       9 0.0% 0.1% Stub:
ToBooleanStub_UndefinedBoolNullSmiSpecObjectStringHeapNumber
       9 0.0% 0.1% LazyCompile: ~Module._compile module.js:364
       9 0.0% 0.1% LazyCompile: *reduceToSingleString util.js:357
       9 0.0% 0.1% Function: ~EventEmitter.addListener events.js:99
       9 0.0% 0.1% Function: ~<anonymous> util.js:324
       8 0.0% 0.1% Stub: StringAddStub
       8 0.0% 0.1% Stub: CallFunctionStub_Args3_Implicit
       8 0.0% 0.1% LazyCompile: ~DoConstructRegExp native regexp.js:35
       8 0.0% 0.1% LazyCompile: ToPrimitive native runtime.js:516
       8 0.0% 0.1% LazyCompile: *objectToString util.js:405
       8 0.0% 0.1% LazyCompile: *Transport.setHandlers
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:89
       8 0.0% 0.1% Function: ~NativeModule.compile node.js:541
       7 0.0% 0.1% Stub: CallFunctionStub
       7 0.0% 0.1% LazyCompile: *diff
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/levenshtein.js:43
       7 0.0% 0.1% LazyCompile:
*StringReplaceGlobalRegExpWithFunction native string.js:396
       7 0.0% 0.1% LazyCompile: $Array.enumerable_ native
v8natives.js:535
       7 0.0% 0.1% KeyedLoadIC: args_count: 0 {2}
       7 0.0% 0.1% Function: ~Module._compile module.js:364
       6 0.0% 0.1% Stub: CompareStub {1}
       6 0.0% 0.1% LazyCompile: *handleInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sourceClock.js:17
       6 0.0% 0.1% LazyCompile: *forEach native array.js:1019
       6 0.0% 0.1% LazyCompile:
*LocalConnectionByNameLRS.aggregateInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:31
       6 0.0% 0.1% LazyCompile: *$Array.configurable_ native
v8natives.js:548
       6 0.0% 0.1% LazyCompile: $Array.get_ native v8natives.js:565
       6 0.0% 0.1% Function: ~ondrain stream.js:46
       6 0.0% 0.1% Function: ~isRegExp util.js:387
       5 0.0% 0.1% Stub: FastNewClosureStub
       5 0.0% 0.1% Stub: CallFunctionStub {2}
       5 0.0% 0.1% Stub: BinaryOpStub_ADD_OverwriteLeft_BothStrings
       5 0.0% 0.1% LazyCompile: ~isArray native array.js:1311
       5 0.0% 0.1% LazyCompile: ~handleInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sourceClock.js:17
       5 0.0% 0.1% LazyCompile: ~VirtualAggregatingLRS.getOrCreateBin
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:31
       5 0.0% 0.1% LazyCompile: res.render
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/lib/view.js:308
       5 0.0% 0.1% LazyCompile: WeekDays native date.js:398
       5 0.0% 0.1% LazyCompile: APPLY_PREPARE native runtime.js:449
       5 0.0% 0.1% LazyCompile:
*PersistentConnection.createConnectionNow
/home/chris/CDRReportServer/tags/1.1.0/common/persistent_connection.js:43
       5 0.0% 0.1% KeyedLoadIC: args_count: 0 {7}
       5 0.0% 0.1% Function: ~Object.getOwnPropertyDescriptor.value
util.js:288
       5 0.0% 0.1% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/middleware/session/memory.js:43
       5 0.0% 0.1% Builtin: A builtin from the snapshot {7}
       4 0.0% 0.0% Stub: ToBooleanStub {2}
       4 0.0% 0.0% Stub: FastNewContextStub {1}
       4 0.0% 0.0% Stub: CompareICStub {2}
       4 0.0% 0.0% Stub: CallFunctionStub_Args6
       4 0.0% 0.0% LazyCompile: ~test native regexp.js:223
       4 0.0% 0.0% LazyCompile: ~stringify native json.js:307
       4 0.0% 0.0% LazyCompile: ~$Array.configurable_ native
v8natives.js:552
       4 0.0% 0.0% LazyCompile: that.emitDebug._table
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:20
       4 0.0% 0.0% LazyCompile: exports.setTimeout timers.js:162
       4 0.0% 0.0% LazyCompile: IN native runtime.js:354
       4 0.0% 0.0% LazyCompile: *toLowerCase native string.js:742
       4 0.0% 0.0% LazyCompile: *min native math.js:140
       4 0.0% 0.0% LazyCompile: *exports.setInterval.timer.ontimeout
timers.js:222
       4 0.0% 0.0% LazyCompile: *encodeURIComponent native uri.js:314
       4 0.0% 0.0% LazyCompile: *afterWrite net.js:494
       4 0.0% 0.0% LazyCompile: *XHRPolling.doWrite
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transports/xhr-polling.js:50
       4 0.0% 0.0% LazyCompile: *Transport.clearHandlers
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:127
       4 0.0% 0.0% LazyCompile:
*MdipSuccessesLimitNLRS.isValidToInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesLimitNLRS.js:37
       4 0.0% 0.0% LazyCompile: *$Array.enumerable_ native
v8natives.js:532
       4 0.0% 0.0% LazyCompile: $Array.writable_ native
v8natives.js:542
       4 0.0% 0.0% KeyedStoreIC: A keyed store IC from the snapshot
       4 0.0% 0.0% Function:
~startup.processNextTick.process._tickCallback node.js:184
       4 0.0% 0.0% Function: ~render
/home/chris/CDRReportServer/tags/1.1.0/frontend/frontend.js:564
       4 0.0% 0.0% Function: ~objectToString util.js:405
       4 0.0% 0.0% Function: ~<anonymous> util.js:238
       4 0.0% 0.0% Function: ~<anonymous> path.js:169
       4 0.0% 0.0% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/middleware/session/memory.js:73
       3 0.0% 0.0% Stub: ToBooleanStub_UndefinedSpecObject
       3 0.0% 0.0% Stub: StringAddStub {2}
       3 0.0% 0.0% Stub: InstanceofStub
       3 0.0% 0.0% Stub: CallFunctionStub_Args6_Implicit
       3 0.0% 0.0% Stub: BinaryOpStub {1}
       3 0.0% 0.0% LazyCompile: ~VirtualAggregatingLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:53
       3 0.0% 0.0% LazyCompile:
~LocalConnectionByNameLRS.aggregateInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:31
       3 0.0% 0.0% LazyCompile: DefineOwnProperty native
v8natives.js:692
       3 0.0% 0.0% LazyCompile: *onread net.js:347
       3 0.0% 0.0% LazyCompile:
*VirtualLRS.init.process.dbcee.runSql.that.rset
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:30
       3 0.0% 0.0% LazyCompile: *Transport.handleRequest.req
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:40
       3 0.0% 0.0% LazyCompile: *NativeModule.require node.js:496
       3 0.0% 0.0% LazyCompile: *$Array.configurable_ native
v8natives.js:552
       3 0.0% 0.0% Function: ~isError util.js:399
       3 0.0% 0.0% Function: ~formatProperty util.js:298
       3 0.0% 0.0% Function: ~formatError util.js:273
       3 0.0% 0.0% Function: ~NativeModule.getCached node.js:520
       3 0.0% 0.0% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sock.js:52
       3 0.0% 0.0% Function:
startup.processNextTick.process._tickCallback node.js:184
       3 0.0% 0.0% Function: Module._compile module.js:364
       3 0.0% 0.0% Builtin: A builtin from the snapshot {6}
       3 0.0% 0.0% Builtin: A builtin from the snapshot {4}
       2 0.0% 0.0% Stub: ToBooleanStub {1}
       2 0.0% 0.0% Stub: KeyedStoreElementStub
       2 0.0% 0.0% Stub: JSEntryStub
       2 0.0% 0.0% Stub: FastNewContextStub
       2 0.0% 0.0% Stub: FastCloneShallowArrayStub {2}
       2 0.0% 0.0% Stub: CompareStub_LT
       2 0.0% 0.0% Stub: CompareICStub {4}
       2 0.0% 0.0% Stub: CompareICStub
       2 0.0% 0.0% Stub: CallFunctionStub {1}
       2 0.0% 0.0% Stub: BinaryOpStub_SUB_Alloc_SMI
       2 0.0% 0.0% Stub: BinaryOpStub_SHR_Alloc_SMI
       2 0.0% 0.0% Stub: BinaryOpStub {2}
       2 0.0% 0.0% LazyCompile: ~ceil native math.js:80
       2 0.0% 0.0% LazyCompile: ~InstantiateFunction native
apinatives.js:65
       2 0.0% 0.0% LazyCompile: levels.forEach.Logger.(anonymous
function) /home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/logger.js:94
       2 0.0% 0.0% LazyCompile: isFinite native v8natives.js:115
       2 0.0% 0.0% LazyCompile: captureStackTrace native
messages.js:1054
       2 0.0% 0.0% LazyCompile: INSTANCE_OF native runtime.js:367
       2 0.0% 0.0% LazyCompile: DefineOneShotAccessor native
messages.js:727
       2 0.0% 0.0% LazyCompile: DELETE native runtime.js:348
       2 0.0% 0.0% LazyCompile: *isDate util.js:393
       2 0.0% 0.0% LazyCompile: *exec native regexp.js:167
       2 0.0% 0.0% LazyCompile: *emitLocalConnection
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:31
       2 0.0% 0.0% LazyCompile: *append _linklist.js:63
       2 0.0% 0.0% LazyCompile: *ToUint32 native runtime.js:596
       2 0.0% 0.0% LazyCompile: *EventEmitter.addListener events.js:99
       2 0.0% 0.0% LazyCompile: *DBCEE.emitDebug
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:80
       2 0.0% 0.0% LazyCompile: *<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/patch.js:33
       2 0.0% 0.0% KeyedLoadIC: args_count: 0 {6}
       2 0.0% 0.0% KeyedLoadIC: A keyed load IC from the snapshot {1}
       2 0.0% 0.0% Function:
~startup.globalTimeouts.global.setInterval node.js:139
       2 0.0% 0.0% Function: ~inspect util.js:94
       2 0.0% 0.0% Function: ~exports.normalize path.js:301
       2 0.0% 0.0% Function: ~dashboard
/home/chris/CDRReportServer/tags/1.1.0/frontend/frontend.js:501
       1 0.0% 0.0% Stub: ToBooleanStub_UndefinedString
       1 0.0% 0.0% Stub: ToBooleanStub_String
       1 0.0% 0.0% Stub: ToBooleanStub_Smi
       1 0.0% 0.0% Stub: StringAddStub {1}
       1 0.0% 0.0% Stub: JSEntryStub {1}
       1 0.0% 0.0% Stub: FastNewContextStub {3}
       1 0.0% 0.0% Stub: FastNewContextStub {2}
       1 0.0% 0.0% Stub: FastCloneShallowArrayStub {1}
       1 0.0% 0.0% Stub: FastCloneShallowArrayStub
       1 0.0% 0.0% Stub: CompareICStub {8}
       1 0.0% 0.0% Stub: CompareICStub {7}
       1 0.0% 0.0% Stub: CompareICStub {6}
       1 0.0% 0.0% Stub: CompareICStub {5}
       1 0.0% 0.0% Stub: CallFunctionStub {3}
       1 0.0% 0.0% Stub: BinaryOpStub
       1 0.0% 0.0% RegExp:
([^:]+):([0-9]+)?(\\+)?:([^:]+)?:?([\\s\\S]*)?
       1 0.0% 0.0% LazyCompile: ~setTime native date.js:771
       1 0.0% 0.0% LazyCompile: ~SubString native string.js:200
       1 0.0% 0.0% LazyCompile: ~NativeModule.require node.js:496
       1 0.0% 0.0% LazyCompile:
~MdipSuccessesInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesInPeriodLRS.js:45
       1 0.0% 0.0% LazyCompile: ~GetOwnEnumerablePropertyNames native
v8natives.js:1011
       1 0.0% 0.0% LazyCompile: ~DoRegExpExec native regexp.js:119
       1 0.0% 0.0% LazyCompile: ~ConfigureTemplateInstance native
apinatives.js:105
       1 0.0% 0.0% LazyCompile: ~BasicJSONSerialize native json.js:273
       1 0.0% 0.0% LazyCompile: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/v8-profiler/v8-profiler.js:1
       1 0.0% 0.0% LazyCompile: ~<anonymous>
       1 0.0% 0.0% LazyCompile: ~$Array.enumerable_ native
v8natives.js:532
       1 0.0% 0.0% LazyCompile: ~$Array.enumerable_ native
v8natives.js:528
       1 0.0% 0.0% LazyCompile: d native v8natives.js:582
       1 0.0% 0.0% LazyCompile: bind native v8natives.js:1456
       1 0.0% 0.0% LazyCompile: b native v8natives.js:1264
       1 0.0% 0.0% LazyCompile: VirtualAggregatingLRS.getOrCreateBin
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:31
       1 0.0% 0.0% LazyCompile: NewFunction native v8natives.js:1527
       1 0.0% 0.0% LazyCompile: EQUALS native runtime.js:54
       1 0.0% 0.0% LazyCompile: COMPARE native runtime.js:120
       1 0.0% 0.0% LazyCompile: ADD native runtime.js:163
       1 0.0% 0.0% LazyCompile: *stylizeNoColor util.js:148
       1 0.0% 0.0% LazyCompile: *sto
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualRollingLRS.js:38
       1 0.0% 0.0% LazyCompile:
*startup.globalTimeouts.global.clearTimeout node.js:144
       1 0.0% 0.0% LazyCompile: *formatValue util.js:153
       1 0.0% 0.0% LazyCompile: *exports.warn console.js:32
       1 0.0% 0.0% LazyCompile: *cmd.process_packet
/home/chris/CDRReportServer/tags/1.1.0/node_modules/mysql-native/lib/mysql-native/command.js:27
       1 0.0% 0.0% LazyCompile: *TxnByTxnStartLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/txnByTxnStartLRS.js:61
       1 0.0% 0.0% LazyCompile: *Transport.handleRequest.req
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:50
       1 0.0% 0.0% LazyCompile: *Socket.dispatch
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/socket.js:228
       1 0.0% 0.0% LazyCompile: *OutgoingMessage.write http.js:588
       1 0.0% 0.0% LazyCompile: *OutgoingMessage.setHeader http.js:524
       1 0.0% 0.0% LazyCompile:
*MdipSuccessesByTxnStartLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesByTxnStartLRS.js:64
       1 0.0% 0.0% LazyCompile: *Manager.get
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/manager.js:156
       1 0.0% 0.0% LazyCompile: *LocalTimezoneString native
date.js:498
       1 0.0% 0.0% LazyCompile: *CryptoStream.resume tls.js:161
       1 0.0% 0.0% LazyCompile: *ConnectionByNameLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/connectionByNameLRS.js:45
       1 0.0% 0.0% LazyCompile: $Array.set_ native v8natives.js:568
       1 0.0% 0.0% KeyedStoreIC: args_count: 0 {9}
       1 0.0% 0.0% KeyedLoadIC: store
       1 0.0% 0.0% KeyedLoadIC: args_count: 0 {8}
       1 0.0% 0.0% KeyedLoadIC: args_count: 0 {5}
       1 0.0% 0.0% KeyedLoadIC: args_count: 0 {4}
       1 0.0% 0.0% KeyedLoadIC: args_count: 0 {3}
       1 0.0% 0.0% KeyedLoadIC: args_count: 0 {1}
       1 0.0% 0.0% KeyedLoadIC: args_count: 0 {10}
       1 0.0% 0.0% Function: ~str util.js:328
       1 0.0% 0.0% Function: ~sto
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualRollingLRS.js:38
       1 0.0% 0.0% Function: ~splitPath path.js:265
       1 0.0% 0.0% Function: ~require.registerExtension module.js:387
       1 0.0% 0.0% Function: ~readPackage module.js:97
       1 0.0% 0.0% Function: ~isBuffer buffer.js:288
       1 0.0% 0.0% Function: ~fs.lstatSync fs.js:419
       1 0.0% 0.0% Function: ~exports.stopProfiling
/home/chris/CDRReportServer/tags/1.1.0/node_modules/v8-profiler/v8-profiler.js:220
       1 0.0% 0.0% Function: ~exports.resolve path.js:272
       1 0.0% 0.0% Function: ~coerce buffer.js:199
       1 0.0% 0.0% Function: ~Stream stream.js:25
       1 0.0% 0.0% Function: ~SlowBuffer.slice buffer.js:185
       1 0.0% 0.0% Function: ~NativeModule.require node.js:496
       1 0.0% 0.0% Function: ~<anonymous> node.js:280
       1 0.0% 0.0% Function: ~<anonymous> fs.js:152

  [C++]:
    ticks total nonlib name

  [GC]:
    ticks total nonlib name
     776 0.6%

  [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
   111345 91.6% /lib/libc-2.12.1.so

--
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
nodejs+[email protected]
For more options, visit this group at
http://groups.google.com/group/nodejs?hl=en?hl=en

Search Discussions

4 responses
Oldest
Nested

Mscdex

at Oct 4, 2012 at 4:56 pm

⇧

On Oct 4, 12:23 pm, Chris Dew wrote:
I'm starting to have a speed problem with a production NodeJS application
(20-100% cpu usage).

Have you tried profiling with idle notifications disabled for
comparison purposes?

reply | permalink

Ben Noordhuis

at Oct 5, 2012 at 2:22 am

⇧

On Thu, Oct 4, 2012 at 6:22 PM, Chris Dew wrote:
I'm starting to have a speed problem with a production NodeJS application
(20-100% cpu usage).

I've run it with --prof and used node-tick-processor.

Is 91% of ticks in libc 'normal'?

It can be, if your application spends a lot of time waiting for new
events in epoll_wait().

A quick way to check that is `strace -c node app.js` and `time node
app.js`. One prints a tally of system calls, the other a breakdown of
system vs. user time.

P.S. is there a way to show the 'unaccounted' ticks? I expect it needs to
be told where to find the source of the app.

Not that I know of.

I don't think it's due to missing sources. Unaccounted ticks are ticks
where V8's profiler thread was not able to make sense of either the
instruction pointer or the stack pointer.

reply | permalink

Perf Tech

at Mar 13, 2014 at 3:02 pm

⇧

I got 80% is in my test on a node based web app. The test was by directing
a client emulator (like "ab") at the app/server.
Majority of the test were spending on

    - Access a few fixed files or directories (open the file/directory,
    fstats, read and close)
       - open file
       - open directory
       - fstats
       - read
       - close

    - socket side;
       - accept
       - getsockname
       - epoll
       - read
       - write

On Thursday, October 4, 2012 11:23:14 AM UTC-5, Chris Dew wrote:

I'm starting to have a speed problem with a production NodeJS application
(20-100% cpu usage).

I've run it with --prof and used node-tick-processor.

Is 91% of ticks in libc 'normal'?

Thanks,

Chris.

P.S. is there a way to show the 'unaccounted' ticks? I expect it needs to
be told where to find the source of the app.

Statistical profiling result from node, (121509 ticks, 7342 unaccounted, 0
excluded).

[Unknown]:
ticks total nonlib name
7342 6.0%

[Shared libraries]:
ticks total nonlib name
111345 91.6% 0.0% /lib/libc-2.12.1.so
248 0.2% 0.0% /lib/libpthread-2.12.1.so
19 0.0% 0.0% /lib/libm-2.12.1.so
19 0.0% 0.0% /lib/libcrypto.so.0.9.8
2 0.0% 0.0% ffffffffff600000-ffffffffff601000
2 0.0% 0.0% 7fff735ff000-7fff73600000
1 0.0% 0.0% /usr/lib/libstdc++.so.6.0.14
1 0.0% 0.0% /lib/libssl.so.0.9.8

[JavaScript]:
ticks total nonlib name
1628 1.3% 16.5% LazyCompile: *Socket._write net.js:470
1391 1.1% 14.1% LazyCompile: *parse native json.js:55
1196 1.0% 12.1% LazyCompile: ~BasicSerializeObject native
json.js:244
372 0.3% 3.8% LazyCompile: stringify native json.js:307
280 0.2% 2.8% LazyCompile: FILTER_KEY native runtime.js:399
266 0.2% 2.7% LazyCompile: TxnInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/txnInPeriodLRS.js:35
260 0.2% 2.6% LazyCompile: *formatProperty util.js:298
221 0.2% 2.2% Function: formatValue util.js:153
208 0.2% 2.1% Function: formatPrimitive util.js:249
206 0.2% 2.1% LazyCompile: *GetOwnProperty native
v8natives.js:649
138 0.1% 1.4% LazyCompile: *indexOf native string.js:115
118 0.1% 1.2% LazyCompile: Join native array.js:119
112 0.1% 1.1% Stub: CEntryStub
107 0.1% 1.1% LazyCompile: *FromPropertyDescriptor native
v8natives.js:385
103 0.1% 1.0% LazyCompile: *keys native v8natives.js:347
88 0.1% 0.9% LazyCompile: *BasicSerializeArray native
json.js:181
86 0.1% 0.9% LazyCompile: ConvertDescriptorArrayToDescriptor
native v8natives.js:593
86 0.1% 0.9% Function: ~Buffer buffer.js:210
82 0.1% 0.8% LazyCompile: PropertyDescriptor native
v8natives.js:494
81 0.1% 0.8% LazyCompile: *EventEmitter.emit events.js:40
79 0.1% 0.8% Function: ~Buffer.write buffer.js:323
72 0.1% 0.7% Function: ~EventEmitter.emit events.js:40
62 0.1% 0.6% Stub: StringAddStub {3}
60 0.0% 0.6% LazyCompile: resultDelta
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/resultdelta.js:7
60 0.0% 0.6% LazyCompile: *RegExpExecNoTests native
regexp.js:156
56 0.0% 0.6% LazyCompile: *indexOf native array.js:1122
50 0.0% 0.5% Stub: NumberToStringStub
49 0.0% 0.5% KeyedLoadIC: A keyed load IC from the snapshot
49 0.0% 0.5% Function: exports.format util.js:23
45 0.0% 0.5% LazyCompile: *map native array.js:1094
39 0.0% 0.4% LazyCompile: *BuildResultFromMatchInfo native
regexp.js:126
39 0.0% 0.4% Builtin: A builtin from the snapshot {2}
38 0.0% 0.4% Stub: CompareICStub {3}
38 0.0% 0.4% Function: ~ondata stream.js:36
38 0.0% 0.4% Builtin: A builtin from the snapshot {3}
37 0.0% 0.4% LazyCompile: *match native string.js:179
36 0.0% 0.4% Stub: RegExpExecStub
33 0.0% 0.3% LazyCompile: hasOwnProperty native
v8natives.js:264
29 0.0% 0.3% Stub: CompareStub
27 0.0% 0.3% LazyCompile: ~keys native v8natives.js:347
25 0.0% 0.3% Stub: ToBooleanStub
24 0.0% 0.2% LazyCompile: VirtualLRS.checkDups
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:219
24 0.0% 0.2% LazyCompile: ToString native runtime.js:560
23 0.0% 0.2% Stub: SubStringStub
23 0.0% 0.2% Builtin: A builtin from the snapshot
22 0.0% 0.2% LazyCompile: *isRegExp util.js:387
21 0.0% 0.2% LazyCompile: *formatArray util.js:278
21 0.0% 0.2% LazyCompile: *VirtualAggregatingLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:53
20 0.0% 0.2% LazyCompile: ~parse native json.js:55
20 0.0% 0.2% LazyCompile: ~join native array.js:399
20 0.0% 0.2% LazyCompile:
MdipSuccessesInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesInPeriodLRS.js:45
20 0.0% 0.2% LazyCompile: *isError util.js:399
20 0.0% 0.2% LazyCompile: *LocalConnectionByNameLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:43
19 0.0% 0.2% LazyCompile: ~indexOf native string.js:115
19 0.0% 0.2% LazyCompile: STRING_ADD_LEFT native runtime.js:183
19 0.0% 0.2% LazyCompile: $Array.get_ native v8natives.js:558
18 0.0% 0.2% LazyCompile: Lev.actions
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/levenshtein.js:52
18 0.0% 0.2% LazyCompile: *UseSparseVariant native array.js:111
18 0.0% 0.2% LazyCompile: *NativeModule.compile node.js:541
17 0.0% 0.2% LazyCompile: *parserOnHeadersComplete http.js:48
16 0.0% 0.2% Stub: CompareICStub {1}
16 0.0% 0.2% LazyCompile: ToObject native runtime.js:577
16 0.0% 0.2% LazyCompile: IsDataDescriptor native
v8natives.js:367
16 0.0% 0.2% LazyCompile: *Socket.write net.js:431
15 0.0% 0.2% Stub: KeyedLoadElementStub
15 0.0% 0.2% LazyCompile: *reduce native array.js:1242
15 0.0% 0.2% LazyCompile: *allocPool buffer.js:281
14 0.0% 0.1% LazyCompile: toString native v8natives.js:238
14 0.0% 0.1% Builtin: A builtin from the snapshot {5}
13 0.0% 0.1% Stub: RegExpConstructResultStub
13 0.0% 0.1% LazyCompile: b native string.js:36
13 0.0% 0.1% LazyCompile: Logger.log
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/logger.js:72
13 0.0% 0.1% LazyCompile: *VirtualLRS.order
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:279
12 0.0% 0.1% LazyCompile: VirtualLRS.emitDeltas
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:234
12 0.0% 0.1% LazyCompile: *socket.ondata http.js:1467
12 0.0% 0.1% LazyCompile: *exports.toArray
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/util.js:18
12 0.0% 0.1% Function: ~<anonymous> util.js:359
12 0.0% 0.1% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sock.js:21
12 0.0% 0.1% Builtin: A builtin from the snapshot {1}
11 0.0% 0.1% LazyCompile: *getOwnPropertyDescriptor native
v8natives.js:870
11 0.0% 0.1% LazyCompile: *VirtualLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:86
11 0.0% 0.1% LazyCompile: *Manager.checkRequest
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/manager.js:897
10 0.0% 0.1% LazyCompile: ~BasicSerializeArray native
json.js:181
10 0.0% 0.1% LazyCompile: *isArray util.js:380
10 0.0% 0.1% LazyCompile: *exports.active timers.js:143
10 0.0% 0.1% LazyCompile: *$Array.enumerable_ native
v8natives.js:528
10 0.0% 0.1% LazyCompile: $Array.writable_ native
v8natives.js:538
10 0.0% 0.1% Function: ~formatValue util.js:153
9 0.0% 0.1% Stub:
ToBooleanStub_UndefinedBoolNullSmiSpecObjectStringHeapNumber
9 0.0% 0.1% LazyCompile: ~Module._compile module.js:364
9 0.0% 0.1% LazyCompile: *reduceToSingleString util.js:357
9 0.0% 0.1% Function: ~EventEmitter.addListener events.js:99
9 0.0% 0.1% Function: ~<anonymous> util.js:324
8 0.0% 0.1% Stub: StringAddStub
8 0.0% 0.1% Stub: CallFunctionStub_Args3_Implicit
8 0.0% 0.1% LazyCompile: ~DoConstructRegExp native
regexp.js:35
8 0.0% 0.1% LazyCompile: ToPrimitive native runtime.js:516
8 0.0% 0.1% LazyCompile: *objectToString util.js:405
8 0.0% 0.1% LazyCompile: *Transport.setHandlers
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:89
8 0.0% 0.1% Function: ~NativeModule.compile node.js:541
7 0.0% 0.1% Stub: CallFunctionStub
7 0.0% 0.1% LazyCompile: *diff
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/levenshtein.js:43
7 0.0% 0.1% LazyCompile:
*StringReplaceGlobalRegExpWithFunction native string.js:396
7 0.0% 0.1% LazyCompile: $Array.enumerable_ native
v8natives.js:535
7 0.0% 0.1% KeyedLoadIC: args_count: 0 {2}
7 0.0% 0.1% Function: ~Module._compile module.js:364
6 0.0% 0.1% Stub: CompareStub {1}
6 0.0% 0.1% LazyCompile: *handleInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sourceClock.js:17
6 0.0% 0.1% LazyCompile: *forEach native array.js:1019
6 0.0% 0.1% LazyCompile:
*LocalConnectionByNameLRS.aggregateInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:31
6 0.0% 0.1% LazyCompile: *$Array.configurable_ native
v8natives.js:548
6 0.0% 0.1% LazyCompile: $Array.get_ native v8natives.js:565
6 0.0% 0.1% Function: ~ondrain stream.js:46
6 0.0% 0.1% Function: ~isRegExp util.js:387
5 0.0% 0.1% Stub: FastNewClosureStub
5 0.0% 0.1% Stub: CallFunctionStub {2}
5 0.0% 0.1% Stub: BinaryOpStub_ADD_OverwriteLeft_BothStrings
5 0.0% 0.1% LazyCompile: ~isArray native array.js:1311
5 0.0% 0.1% LazyCompile: ~handleInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sourceClock.js:17
5 0.0% 0.1% LazyCompile:
~VirtualAggregatingLRS.getOrCreateBin
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:31
5 0.0% 0.1% LazyCompile: res.render
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/lib/view.js:308
5 0.0% 0.1% LazyCompile: WeekDays native date.js:398
5 0.0% 0.1% LazyCompile: APPLY_PREPARE native runtime.js:449
5 0.0% 0.1% LazyCompile:
*PersistentConnection.createConnectionNow
/home/chris/CDRReportServer/tags/1.1.0/common/persistent_connection.js:43
5 0.0% 0.1% KeyedLoadIC: args_count: 0 {7}
5 0.0% 0.1% Function: ~Object.getOwnPropertyDescriptor.value
util.js:288
5 0.0% 0.1% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/middleware/session/memory.js:43
5 0.0% 0.1% Builtin: A builtin from the snapshot {7}
4 0.0% 0.0% Stub: ToBooleanStub {2}
4 0.0% 0.0% Stub: FastNewContextStub {1}
4 0.0% 0.0% Stub: CompareICStub {2}
4 0.0% 0.0% Stub: CallFunctionStub_Args6
4 0.0% 0.0% LazyCompile: ~test native regexp.js:223
4 0.0% 0.0% LazyCompile: ~stringify native json.js:307
4 0.0% 0.0% LazyCompile: ~$Array.configurable_ native
v8natives.js:552
4 0.0% 0.0% LazyCompile: that.emitDebug._table
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:20
4 0.0% 0.0% LazyCompile: exports.setTimeout timers.js:162
4 0.0% 0.0% LazyCompile: IN native runtime.js:354
4 0.0% 0.0% LazyCompile: *toLowerCase native string.js:742
4 0.0% 0.0% LazyCompile: *min native math.js:140
4 0.0% 0.0% LazyCompile: *exports.setInterval.timer.ontimeout
timers.js:222
4 0.0% 0.0% LazyCompile: *encodeURIComponent native uri.js:314
4 0.0% 0.0% LazyCompile: *afterWrite net.js:494
4 0.0% 0.0% LazyCompile: *XHRPolling.doWrite
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transports/xhr-polling.js:50
4 0.0% 0.0% LazyCompile: *Transport.clearHandlers
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:127
4 0.0% 0.0% LazyCompile:
*MdipSuccessesLimitNLRS.isValidToInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesLimitNLRS.js:37
4 0.0% 0.0% LazyCompile: *$Array.enumerable_ native
v8natives.js:532
4 0.0% 0.0% LazyCompile: $Array.writable_ native
v8natives.js:542
4 0.0% 0.0% KeyedStoreIC: A keyed store IC from the snapshot
4 0.0% 0.0% Function:
~startup.processNextTick.process._tickCallback node.js:184
4 0.0% 0.0% Function: ~render
/home/chris/CDRReportServer/tags/1.1.0/frontend/frontend.js:564
4 0.0% 0.0% Function: ~objectToString util.js:405
4 0.0% 0.0% Function: ~<anonymous> util.js:238
4 0.0% 0.0% Function: ~<anonymous> path.js:169
4 0.0% 0.0% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/middleware/session/memory.js:73
3 0.0% 0.0% Stub: ToBooleanStub_UndefinedSpecObject
3 0.0% 0.0% Stub: StringAddStub {2}
3 0.0% 0.0% Stub: InstanceofStub
3 0.0% 0.0% Stub: CallFunctionStub_Args6_Implicit
3 0.0% 0.0% Stub: BinaryOpStub {1}
3 0.0% 0.0% LazyCompile: ~VirtualAggregatingLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:53
3 0.0% 0.0% LazyCompile:
~LocalConnectionByNameLRS.aggregateInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:31
3 0.0% 0.0% LazyCompile: DefineOwnProperty native
v8natives.js:692
3 0.0% 0.0% LazyCompile: *onread net.js:347
3 0.0% 0.0% LazyCompile:
*VirtualLRS.init.process.dbcee.runSql.that.rset
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:30
3 0.0% 0.0% LazyCompile: *Transport.handleRequest.req
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:40
3 0.0% 0.0% LazyCompile: *NativeModule.require node.js:496
3 0.0% 0.0% LazyCompile: *$Array.configurable_ native
v8natives.js:552
3 0.0% 0.0% Function: ~isError util.js:399
3 0.0% 0.0% Function: ~formatProperty util.js:298
3 0.0% 0.0% Function: ~formatError util.js:273
3 0.0% 0.0% Function: ~NativeModule.getCached node.js:520
3 0.0% 0.0% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sock.js:52
3 0.0% 0.0% Function:
startup.processNextTick.process._tickCallback node.js:184
3 0.0% 0.0% Function: Module._compile module.js:364
3 0.0% 0.0% Builtin: A builtin from the snapshot {6}
3 0.0% 0.0% Builtin: A builtin from the snapshot {4}
2 0.0% 0.0% Stub: ToBooleanStub {1}
2 0.0% 0.0% Stub: KeyedStoreElementStub
2 0.0% 0.0% Stub: JSEntryStub
2 0.0% 0.0% Stub: FastNewContextStub
2 0.0% 0.0% Stub: FastCloneShallowArrayStub {2}
2 0.0% 0.0% Stub: CompareStub_LT
2 0.0% 0.0% Stub: CompareICStub {4}
2 0.0% 0.0% Stub: CompareICStub
2 0.0% 0.0% Stub: CallFunctionStub {1}
2 0.0% 0.0% Stub: BinaryOpStub_SUB_Alloc_SMI
2 0.0% 0.0% Stub: BinaryOpStub_SHR_Alloc_SMI
2 0.0% 0.0% Stub: BinaryOpStub {2}
2 0.0% 0.0% LazyCompile: ~ceil native math.js:80
2 0.0% 0.0% LazyCompile: ~InstantiateFunction native
apinatives.js:65
2 0.0% 0.0% LazyCompile: levels.forEach.Logger.(anonymous
function) /home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/logger.js:94
2 0.0% 0.0% LazyCompile: isFinite native v8natives.js:115
2 0.0% 0.0% LazyCompile: captureStackTrace native
messages.js:1054
2 0.0% 0.0% LazyCompile: INSTANCE_OF native runtime.js:367
2 0.0% 0.0% LazyCompile: DefineOneShotAccessor native
messages.js:727
2 0.0% 0.0% LazyCompile: DELETE native runtime.js:348
2 0.0% 0.0% LazyCompile: *isDate util.js:393
2 0.0% 0.0% LazyCompile: *exec native regexp.js:167
2 0.0% 0.0% LazyCompile: *emitLocalConnection
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:31
2 0.0% 0.0% LazyCompile: *append _linklist.js:63
2 0.0% 0.0% LazyCompile: *ToUint32 native runtime.js:596
2 0.0% 0.0% LazyCompile: *EventEmitter.addListener
events.js:99
2 0.0% 0.0% LazyCompile: *DBCEE.emitDebug
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:80
2 0.0% 0.0% LazyCompile: *<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/patch.js:33
2 0.0% 0.0% KeyedLoadIC: args_count: 0 {6}
2 0.0% 0.0% KeyedLoadIC: A keyed load IC from the snapshot {1}
2 0.0% 0.0% Function:
~startup.globalTimeouts.global.setInterval node.js:139
2 0.0% 0.0% Function: ~inspect util.js:94
2 0.0% 0.0% Function: ~exports.normalize path.js:301
2 0.0% 0.0% Function: ~dashboard
/home/chris/CDRReportServer/tags/1.1.0/frontend/frontend.js:501
1 0.0% 0.0% Stub: ToBooleanStub_UndefinedString
1 0.0% 0.0% Stub: ToBooleanStub_String
1 0.0% 0.0% Stub: ToBooleanStub_Smi
1 0.0% 0.0% Stub: StringAddStub {1}
1 0.0% 0.0% Stub: JSEntryStub {1}
1 0.0% 0.0% Stub: FastNewContextStub {3}
1 0.0% 0.0% Stub: FastNewContextStub {2}
1 0.0% 0.0% Stub: FastCloneShallowArrayStub {1}
1 0.0% 0.0% Stub: FastCloneShallowArrayStub
1 0.0% 0.0% Stub: CompareICStub {8}
1 0.0% 0.0% Stub: CompareICStub {7}
1 0.0% 0.0% Stub: CompareICStub {6}
1 0.0% 0.0% Stub: CompareICStub {5}
1 0.0% 0.0% Stub: CallFunctionStub {3}
1 0.0% 0.0% Stub: BinaryOpStub
1 0.0% 0.0% RegExp:
([^:]+):([0-9]+)?(\\+)?:([^:]+)?:?([\\s\\S]*)?
1 0.0% 0.0% LazyCompile: ~setTime native date.js:771
1 0.0% 0.0% LazyCompile: ~SubString native string.js:200
1 0.0% 0.0% LazyCompile: ~NativeModule.require node.js:496
1 0.0% 0.0% LazyCompile:
~MdipSuccessesInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesInPeriodLRS.js:45
1 0.0% 0.0% LazyCompile: ~GetOwnEnumerablePropertyNames
native v8natives.js:1011
1 0.0% 0.0% LazyCompile: ~DoRegExpExec native regexp.js:119
1 0.0% 0.0% LazyCompile: ~ConfigureTemplateInstance native
apinatives.js:105
1 0.0% 0.0% LazyCompile: ~BasicJSONSerialize native
json.js:273
1 0.0% 0.0% LazyCompile: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/v8-profiler/v8-profiler.js:1
1 0.0% 0.0% LazyCompile: ~<anonymous>
1 0.0% 0.0% LazyCompile: ~$Array.enumerable_ native
v8natives.js:532
1 0.0% 0.0% LazyCompile: ~$Array.enumerable_ native
v8natives.js:528
1 0.0% 0.0% LazyCompile: d native v8natives.js:582
1 0.0% 0.0% LazyCompile: bind native v8natives.js:1456
1 0.0% 0.0% LazyCompile: b native v8natives.js:1264
1 0.0% 0.0% LazyCompile: VirtualAggregatingLRS.getOrCreateBin
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:31
1 0.0% 0.0% LazyCompile: NewFunction native v8natives.js:1527
1 0.0% 0.0% LazyCompile: EQUALS native runtime.js:54
1 0.0% 0.0% LazyCompile: COMPARE native runtime.js:120
1 0.0% 0.0% LazyCompile: ADD native runtime.js:163
1 0.0% 0.0% LazyCompile: *stylizeNoColor util.js:148
1 0.0% 0.0% LazyCompile: *sto
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualRollingLRS.js:38
1 0.0% 0.0% LazyCompile:
*startup.globalTimeouts.global.clearTimeout node.js:144
1 0.0% 0.0% LazyCompile: *formatValue util.js:153
1 0.0% 0.0% LazyCompile: *exports.warn console.js:32
1 0.0% 0.0% LazyCompile: *cmd.process_packet
/home/chris/CDRReportServer/tags/1.1.0/node_modules/mysql-native/lib/mysql-native/command.js:27
1 0.0% 0.0% LazyCompile: *TxnByTxnStartLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/txnByTxnStartLRS.js:61
1 0.0% 0.0% LazyCompile: *Transport.handleRequest.req
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:50
1 0.0% 0.0% LazyCompile: *Socket.dispatch
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/socket.js:228
1 0.0% 0.0% LazyCompile: *OutgoingMessage.write http.js:588
1 0.0% 0.0% LazyCompile: *OutgoingMessage.setHeader
http.js:524
1 0.0% 0.0% LazyCompile:
*MdipSuccessesByTxnStartLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesByTxnStartLRS.js:64
1 0.0% 0.0% LazyCompile: *Manager.get
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/manager.js:156
1 0.0% 0.0% LazyCompile: *LocalTimezoneString native
date.js:498
1 0.0% 0.0% LazyCompile: *CryptoStream.resume tls.js:161
1 0.0% 0.0% LazyCompile: *ConnectionByNameLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/connectionByNameLRS.js:45
1 0.0% 0.0% LazyCompile: $Array.set_ native v8natives.js:568
1 0.0% 0.0% KeyedStoreIC: args_count: 0 {9}
1 0.0% 0.0% KeyedLoadIC: store
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {8}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {5}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {4}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {3}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {1}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {10}
1 0.0% 0.0% Function: ~str util.js:328
1 0.0% 0.0% Function: ~sto
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualRollingLRS.js:38
1 0.0% 0.0% Function: ~splitPath path.js:265
1 0.0% 0.0% Function: ~require.registerExtension module.js:387
1 0.0% 0.0% Function: ~readPackage module.js:97
1 0.0% 0.0% Function: ~isBuffer buffer.js:288
1 0.0% 0.0% Function: ~fs.lstatSync fs.js:419
1 0.0% 0.0% Function: ~exports.stopProfiling
/home/chris/CDRReportServer/tags/1.1.0/node_modules/v8-profiler/v8-profiler.js:220
1 0.0% 0.0% Function: ~exports.resolve path.js:272
1 0.0% 0.0% Function: ~coerce buffer.js:199
1 0.0% 0.0% Function: ~Stream stream.js:25
1 0.0% 0.0% Function: ~SlowBuffer.slice buffer.js:185
1 0.0% 0.0% Function: ~NativeModule.require node.js:496
1 0.0% 0.0% Function: ~<anonymous> node.js:280
1 0.0% 0.0% Function: ~<anonymous> fs.js:152

[C++]:
ticks total nonlib name

[GC]:
ticks total nonlib name
776 0.6%

[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
111345 91.6% /lib/libc-2.12.1.so

--
--
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
nodejs+[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/d/optout.

reply | permalink

Michael Hart

at Mar 14, 2014 at 3:30 am

⇧

Make sure you're using the deps from your actual node version too - I've
run into problems with this before, so I just use this gist
now: https://gist.github.com/mhart/5107424

(curl https://raw.github.com/bnoordhuis/node-profiler/master/tools/nprof-stub.js; \
for file in splaytree codemap csvparser consarray profile profile_view logreader tickprocessor tickprocessor-driver; \
do curl https://raw.github.com/joyent/node/$(node --version)/deps/v8/tools/$file.js; \
done) > nprof && chmod 755 nprof

(and then run `nprof` whereever you have your v8.log)

On Friday, 5 October 2012 02:23:14 UTC+10, Chris Dew wrote:

I'm starting to have a speed problem with a production NodeJS application
(20-100% cpu usage).

I've run it with --prof and used node-tick-processor.

Is 91% of ticks in libc 'normal'?

Thanks,

Chris.

P.S. is there a way to show the 'unaccounted' ticks? I expect it needs to
be told where to find the source of the app.

Statistical profiling result from node, (121509 ticks, 7342 unaccounted, 0
excluded).

[Unknown]:
ticks total nonlib name
7342 6.0%

[Shared libraries]:
ticks total nonlib name
111345 91.6% 0.0% /lib/libc-2.12.1.so
248 0.2% 0.0% /lib/libpthread-2.12.1.so
19 0.0% 0.0% /lib/libm-2.12.1.so
19 0.0% 0.0% /lib/libcrypto.so.0.9.8
2 0.0% 0.0% ffffffffff600000-ffffffffff601000
2 0.0% 0.0% 7fff735ff000-7fff73600000
1 0.0% 0.0% /usr/lib/libstdc++.so.6.0.14
1 0.0% 0.0% /lib/libssl.so.0.9.8

[JavaScript]:
ticks total nonlib name
1628 1.3% 16.5% LazyCompile: *Socket._write net.js:470
1391 1.1% 14.1% LazyCompile: *parse native json.js:55
1196 1.0% 12.1% LazyCompile: ~BasicSerializeObject native
json.js:244
372 0.3% 3.8% LazyCompile: stringify native json.js:307
280 0.2% 2.8% LazyCompile: FILTER_KEY native runtime.js:399
266 0.2% 2.7% LazyCompile: TxnInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/txnInPeriodLRS.js:35
260 0.2% 2.6% LazyCompile: *formatProperty util.js:298
221 0.2% 2.2% Function: formatValue util.js:153
208 0.2% 2.1% Function: formatPrimitive util.js:249
206 0.2% 2.1% LazyCompile: *GetOwnProperty native
v8natives.js:649
138 0.1% 1.4% LazyCompile: *indexOf native string.js:115
118 0.1% 1.2% LazyCompile: Join native array.js:119
112 0.1% 1.1% Stub: CEntryStub
107 0.1% 1.1% LazyCompile: *FromPropertyDescriptor native
v8natives.js:385
103 0.1% 1.0% LazyCompile: *keys native v8natives.js:347
88 0.1% 0.9% LazyCompile: *BasicSerializeArray native
json.js:181
86 0.1% 0.9% LazyCompile: ConvertDescriptorArrayToDescriptor
native v8natives.js:593
86 0.1% 0.9% Function: ~Buffer buffer.js:210
82 0.1% 0.8% LazyCompile: PropertyDescriptor native
v8natives.js:494
81 0.1% 0.8% LazyCompile: *EventEmitter.emit events.js:40
79 0.1% 0.8% Function: ~Buffer.write buffer.js:323
72 0.1% 0.7% Function: ~EventEmitter.emit events.js:40
62 0.1% 0.6% Stub: StringAddStub {3}
60 0.0% 0.6% LazyCompile: resultDelta
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/resultdelta.js:7
60 0.0% 0.6% LazyCompile: *RegExpExecNoTests native
regexp.js:156
56 0.0% 0.6% LazyCompile: *indexOf native array.js:1122
50 0.0% 0.5% Stub: NumberToStringStub
49 0.0% 0.5% KeyedLoadIC: A keyed load IC from the snapshot
49 0.0% 0.5% Function: exports.format util.js:23
45 0.0% 0.5% LazyCompile: *map native array.js:1094
39 0.0% 0.4% LazyCompile: *BuildResultFromMatchInfo native
regexp.js:126
39 0.0% 0.4% Builtin: A builtin from the snapshot {2}
38 0.0% 0.4% Stub: CompareICStub {3}
38 0.0% 0.4% Function: ~ondata stream.js:36
38 0.0% 0.4% Builtin: A builtin from the snapshot {3}
37 0.0% 0.4% LazyCompile: *match native string.js:179
36 0.0% 0.4% Stub: RegExpExecStub
33 0.0% 0.3% LazyCompile: hasOwnProperty native
v8natives.js:264
29 0.0% 0.3% Stub: CompareStub
27 0.0% 0.3% LazyCompile: ~keys native v8natives.js:347
25 0.0% 0.3% Stub: ToBooleanStub
24 0.0% 0.2% LazyCompile: VirtualLRS.checkDups
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:219
24 0.0% 0.2% LazyCompile: ToString native runtime.js:560
23 0.0% 0.2% Stub: SubStringStub
23 0.0% 0.2% Builtin: A builtin from the snapshot
22 0.0% 0.2% LazyCompile: *isRegExp util.js:387
21 0.0% 0.2% LazyCompile: *formatArray util.js:278
21 0.0% 0.2% LazyCompile: *VirtualAggregatingLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:53
20 0.0% 0.2% LazyCompile: ~parse native json.js:55
20 0.0% 0.2% LazyCompile: ~join native array.js:399
20 0.0% 0.2% LazyCompile:
MdipSuccessesInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesInPeriodLRS.js:45
20 0.0% 0.2% LazyCompile: *isError util.js:399
20 0.0% 0.2% LazyCompile: *LocalConnectionByNameLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:43
19 0.0% 0.2% LazyCompile: ~indexOf native string.js:115
19 0.0% 0.2% LazyCompile: STRING_ADD_LEFT native runtime.js:183
19 0.0% 0.2% LazyCompile: $Array.get_ native v8natives.js:558
18 0.0% 0.2% LazyCompile: Lev.actions
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/levenshtein.js:52
18 0.0% 0.2% LazyCompile: *UseSparseVariant native array.js:111
18 0.0% 0.2% LazyCompile: *NativeModule.compile node.js:541
17 0.0% 0.2% LazyCompile: *parserOnHeadersComplete http.js:48
16 0.0% 0.2% Stub: CompareICStub {1}
16 0.0% 0.2% LazyCompile: ToObject native runtime.js:577
16 0.0% 0.2% LazyCompile: IsDataDescriptor native
v8natives.js:367
16 0.0% 0.2% LazyCompile: *Socket.write net.js:431
15 0.0% 0.2% Stub: KeyedLoadElementStub
15 0.0% 0.2% LazyCompile: *reduce native array.js:1242
15 0.0% 0.2% LazyCompile: *allocPool buffer.js:281
14 0.0% 0.1% LazyCompile: toString native v8natives.js:238
14 0.0% 0.1% Builtin: A builtin from the snapshot {5}
13 0.0% 0.1% Stub: RegExpConstructResultStub
13 0.0% 0.1% LazyCompile: b native string.js:36
13 0.0% 0.1% LazyCompile: Logger.log
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/logger.js:72
13 0.0% 0.1% LazyCompile: *VirtualLRS.order
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:279
12 0.0% 0.1% LazyCompile: VirtualLRS.emitDeltas
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:234
12 0.0% 0.1% LazyCompile: *socket.ondata http.js:1467
12 0.0% 0.1% LazyCompile: *exports.toArray
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/util.js:18
12 0.0% 0.1% Function: ~<anonymous> util.js:359
12 0.0% 0.1% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sock.js:21
12 0.0% 0.1% Builtin: A builtin from the snapshot {1}
11 0.0% 0.1% LazyCompile: *getOwnPropertyDescriptor native
v8natives.js:870
11 0.0% 0.1% LazyCompile: *VirtualLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:86
11 0.0% 0.1% LazyCompile: *Manager.checkRequest
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/manager.js:897
10 0.0% 0.1% LazyCompile: ~BasicSerializeArray native
json.js:181
10 0.0% 0.1% LazyCompile: *isArray util.js:380
10 0.0% 0.1% LazyCompile: *exports.active timers.js:143
10 0.0% 0.1% LazyCompile: *$Array.enumerable_ native
v8natives.js:528
10 0.0% 0.1% LazyCompile: $Array.writable_ native
v8natives.js:538
10 0.0% 0.1% Function: ~formatValue util.js:153
9 0.0% 0.1% Stub:
ToBooleanStub_UndefinedBoolNullSmiSpecObjectStringHeapNumber
9 0.0% 0.1% LazyCompile: ~Module._compile module.js:364
9 0.0% 0.1% LazyCompile: *reduceToSingleString util.js:357
9 0.0% 0.1% Function: ~EventEmitter.addListener events.js:99
9 0.0% 0.1% Function: ~<anonymous> util.js:324
8 0.0% 0.1% Stub: StringAddStub
8 0.0% 0.1% Stub: CallFunctionStub_Args3_Implicit
8 0.0% 0.1% LazyCompile: ~DoConstructRegExp native
regexp.js:35
8 0.0% 0.1% LazyCompile: ToPrimitive native runtime.js:516
8 0.0% 0.1% LazyCompile: *objectToString util.js:405
8 0.0% 0.1% LazyCompile: *Transport.setHandlers
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:89
8 0.0% 0.1% Function: ~NativeModule.compile node.js:541
7 0.0% 0.1% Stub: CallFunctionStub
7 0.0% 0.1% LazyCompile: *diff
/home/chris/CDRReportServer/tags/1.1.0/common/levenshtein/lib/levenshtein.js:43
7 0.0% 0.1% LazyCompile:
*StringReplaceGlobalRegExpWithFunction native string.js:396
7 0.0% 0.1% LazyCompile: $Array.enumerable_ native
v8natives.js:535
7 0.0% 0.1% KeyedLoadIC: args_count: 0 {2}
7 0.0% 0.1% Function: ~Module._compile module.js:364
6 0.0% 0.1% Stub: CompareStub {1}
6 0.0% 0.1% LazyCompile: *handleInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sourceClock.js:17
6 0.0% 0.1% LazyCompile: *forEach native array.js:1019
6 0.0% 0.1% LazyCompile:
*LocalConnectionByNameLRS.aggregateInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:31
6 0.0% 0.1% LazyCompile: *$Array.configurable_ native
v8natives.js:548
6 0.0% 0.1% LazyCompile: $Array.get_ native v8natives.js:565
6 0.0% 0.1% Function: ~ondrain stream.js:46
6 0.0% 0.1% Function: ~isRegExp util.js:387
5 0.0% 0.1% Stub: FastNewClosureStub
5 0.0% 0.1% Stub: CallFunctionStub {2}
5 0.0% 0.1% Stub: BinaryOpStub_ADD_OverwriteLeft_BothStrings
5 0.0% 0.1% LazyCompile: ~isArray native array.js:1311
5 0.0% 0.1% LazyCompile: ~handleInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sourceClock.js:17
5 0.0% 0.1% LazyCompile:
~VirtualAggregatingLRS.getOrCreateBin
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:31
5 0.0% 0.1% LazyCompile: res.render
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/lib/view.js:308
5 0.0% 0.1% LazyCompile: WeekDays native date.js:398
5 0.0% 0.1% LazyCompile: APPLY_PREPARE native runtime.js:449
5 0.0% 0.1% LazyCompile:
*PersistentConnection.createConnectionNow
/home/chris/CDRReportServer/tags/1.1.0/common/persistent_connection.js:43
5 0.0% 0.1% KeyedLoadIC: args_count: 0 {7}
5 0.0% 0.1% Function: ~Object.getOwnPropertyDescriptor.value
util.js:288
5 0.0% 0.1% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/middleware/session/memory.js:43
5 0.0% 0.1% Builtin: A builtin from the snapshot {7}
4 0.0% 0.0% Stub: ToBooleanStub {2}
4 0.0% 0.0% Stub: FastNewContextStub {1}
4 0.0% 0.0% Stub: CompareICStub {2}
4 0.0% 0.0% Stub: CallFunctionStub_Args6
4 0.0% 0.0% LazyCompile: ~test native regexp.js:223
4 0.0% 0.0% LazyCompile: ~stringify native json.js:307
4 0.0% 0.0% LazyCompile: ~$Array.configurable_ native
v8natives.js:552
4 0.0% 0.0% LazyCompile: that.emitDebug._table
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:20
4 0.0% 0.0% LazyCompile: exports.setTimeout timers.js:162
4 0.0% 0.0% LazyCompile: IN native runtime.js:354
4 0.0% 0.0% LazyCompile: *toLowerCase native string.js:742
4 0.0% 0.0% LazyCompile: *min native math.js:140
4 0.0% 0.0% LazyCompile: *exports.setInterval.timer.ontimeout
timers.js:222
4 0.0% 0.0% LazyCompile: *encodeURIComponent native uri.js:314
4 0.0% 0.0% LazyCompile: *afterWrite net.js:494
4 0.0% 0.0% LazyCompile: *XHRPolling.doWrite
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transports/xhr-polling.js:50
4 0.0% 0.0% LazyCompile: *Transport.clearHandlers
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:127
4 0.0% 0.0% LazyCompile:
*MdipSuccessesLimitNLRS.isValidToInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesLimitNLRS.js:37
4 0.0% 0.0% LazyCompile: *$Array.enumerable_ native
v8natives.js:532
4 0.0% 0.0% LazyCompile: $Array.writable_ native
v8natives.js:542
4 0.0% 0.0% KeyedStoreIC: A keyed store IC from the snapshot
4 0.0% 0.0% Function:
~startup.processNextTick.process._tickCallback node.js:184
4 0.0% 0.0% Function: ~render
/home/chris/CDRReportServer/tags/1.1.0/frontend/frontend.js:564
4 0.0% 0.0% Function: ~objectToString util.js:405
4 0.0% 0.0% Function: ~<anonymous> util.js:238
4 0.0% 0.0% Function: ~<anonymous> path.js:169
4 0.0% 0.0% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/middleware/session/memory.js:73
3 0.0% 0.0% Stub: ToBooleanStub_UndefinedSpecObject
3 0.0% 0.0% Stub: StringAddStub {2}
3 0.0% 0.0% Stub: InstanceofStub
3 0.0% 0.0% Stub: CallFunctionStub_Args6_Implicit
3 0.0% 0.0% Stub: BinaryOpStub {1}
3 0.0% 0.0% LazyCompile: ~VirtualAggregatingLRS.onInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:53
3 0.0% 0.0% LazyCompile:
~LocalConnectionByNameLRS.aggregateInsert
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/localConnectionByNameLRS.js:31
3 0.0% 0.0% LazyCompile: DefineOwnProperty native
v8natives.js:692
3 0.0% 0.0% LazyCompile: *onread net.js:347
3 0.0% 0.0% LazyCompile:
*VirtualLRS.init.process.dbcee.runSql.that.rset
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualLRS.js:30
3 0.0% 0.0% LazyCompile: *Transport.handleRequest.req
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:40
3 0.0% 0.0% LazyCompile: *NativeModule.require node.js:496
3 0.0% 0.0% LazyCompile: *$Array.configurable_ native
v8natives.js:552
3 0.0% 0.0% Function: ~isError util.js:399
3 0.0% 0.0% Function: ~formatProperty util.js:298
3 0.0% 0.0% Function: ~formatError util.js:273
3 0.0% 0.0% Function: ~NativeModule.getCached node.js:520
3 0.0% 0.0% Function: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/sock.js:52
3 0.0% 0.0% Function:
startup.processNextTick.process._tickCallback node.js:184
3 0.0% 0.0% Function: Module._compile module.js:364
3 0.0% 0.0% Builtin: A builtin from the snapshot {6}
3 0.0% 0.0% Builtin: A builtin from the snapshot {4}
2 0.0% 0.0% Stub: ToBooleanStub {1}
2 0.0% 0.0% Stub: KeyedStoreElementStub
2 0.0% 0.0% Stub: JSEntryStub
2 0.0% 0.0% Stub: FastNewContextStub
2 0.0% 0.0% Stub: FastCloneShallowArrayStub {2}
2 0.0% 0.0% Stub: CompareStub_LT
2 0.0% 0.0% Stub: CompareICStub {4}
2 0.0% 0.0% Stub: CompareICStub
2 0.0% 0.0% Stub: CallFunctionStub {1}
2 0.0% 0.0% Stub: BinaryOpStub_SUB_Alloc_SMI
2 0.0% 0.0% Stub: BinaryOpStub_SHR_Alloc_SMI
2 0.0% 0.0% Stub: BinaryOpStub {2}
2 0.0% 0.0% LazyCompile: ~ceil native math.js:80
2 0.0% 0.0% LazyCompile: ~InstantiateFunction native
apinatives.js:65
2 0.0% 0.0% LazyCompile: levels.forEach.Logger.(anonymous
function) /home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/logger.js:94
2 0.0% 0.0% LazyCompile: isFinite native v8natives.js:115
2 0.0% 0.0% LazyCompile: captureStackTrace native
messages.js:1054
2 0.0% 0.0% LazyCompile: INSTANCE_OF native runtime.js:367
2 0.0% 0.0% LazyCompile: DefineOneShotAccessor native
messages.js:727
2 0.0% 0.0% LazyCompile: DELETE native runtime.js:348
2 0.0% 0.0% LazyCompile: *isDate util.js:393
2 0.0% 0.0% LazyCompile: *exec native regexp.js:167
2 0.0% 0.0% LazyCompile: *emitLocalConnection
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:31
2 0.0% 0.0% LazyCompile: *append _linklist.js:63
2 0.0% 0.0% LazyCompile: *ToUint32 native runtime.js:596
2 0.0% 0.0% LazyCompile: *EventEmitter.addListener
events.js:99
2 0.0% 0.0% LazyCompile: *DBCEE.emitDebug
/home/chris/CDRReportServer/tags/1.1.0/frontend/lib/dbcee.js:80
2 0.0% 0.0% LazyCompile: *<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/express/node_modules/connect/lib/patch.js:33
2 0.0% 0.0% KeyedLoadIC: args_count: 0 {6}
2 0.0% 0.0% KeyedLoadIC: A keyed load IC from the snapshot {1}
2 0.0% 0.0% Function:
~startup.globalTimeouts.global.setInterval node.js:139
2 0.0% 0.0% Function: ~inspect util.js:94
2 0.0% 0.0% Function: ~exports.normalize path.js:301
2 0.0% 0.0% Function: ~dashboard
/home/chris/CDRReportServer/tags/1.1.0/frontend/frontend.js:501
1 0.0% 0.0% Stub: ToBooleanStub_UndefinedString
1 0.0% 0.0% Stub: ToBooleanStub_String
1 0.0% 0.0% Stub: ToBooleanStub_Smi
1 0.0% 0.0% Stub: StringAddStub {1}
1 0.0% 0.0% Stub: JSEntryStub {1}
1 0.0% 0.0% Stub: FastNewContextStub {3}
1 0.0% 0.0% Stub: FastNewContextStub {2}
1 0.0% 0.0% Stub: FastCloneShallowArrayStub {1}
1 0.0% 0.0% Stub: FastCloneShallowArrayStub
1 0.0% 0.0% Stub: CompareICStub {8}
1 0.0% 0.0% Stub: CompareICStub {7}
1 0.0% 0.0% Stub: CompareICStub {6}
1 0.0% 0.0% Stub: CompareICStub {5}
1 0.0% 0.0% Stub: CallFunctionStub {3}
1 0.0% 0.0% Stub: BinaryOpStub
1 0.0% 0.0% RegExp:
([^:]+):([0-9]+)?(\\+)?:([^:]+)?:?([\\s\\S]*)?
1 0.0% 0.0% LazyCompile: ~setTime native date.js:771
1 0.0% 0.0% LazyCompile: ~SubString native string.js:200
1 0.0% 0.0% LazyCompile: ~NativeModule.require node.js:496
1 0.0% 0.0% LazyCompile:
~MdipSuccessesInPeriodLRS.getResultSet
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesInPeriodLRS.js:45
1 0.0% 0.0% LazyCompile: ~GetOwnEnumerablePropertyNames
native v8natives.js:1011
1 0.0% 0.0% LazyCompile: ~DoRegExpExec native regexp.js:119
1 0.0% 0.0% LazyCompile: ~ConfigureTemplateInstance native
apinatives.js:105
1 0.0% 0.0% LazyCompile: ~BasicJSONSerialize native
json.js:273
1 0.0% 0.0% LazyCompile: ~<anonymous>
/home/chris/CDRReportServer/tags/1.1.0/node_modules/v8-profiler/v8-profiler.js:1
1 0.0% 0.0% LazyCompile: ~<anonymous>
1 0.0% 0.0% LazyCompile: ~$Array.enumerable_ native
v8natives.js:532
1 0.0% 0.0% LazyCompile: ~$Array.enumerable_ native
v8natives.js:528
1 0.0% 0.0% LazyCompile: d native v8natives.js:582
1 0.0% 0.0% LazyCompile: bind native v8natives.js:1456
1 0.0% 0.0% LazyCompile: b native v8natives.js:1264
1 0.0% 0.0% LazyCompile: VirtualAggregatingLRS.getOrCreateBin
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualAggregatingLRS.js:31
1 0.0% 0.0% LazyCompile: NewFunction native v8natives.js:1527
1 0.0% 0.0% LazyCompile: EQUALS native runtime.js:54
1 0.0% 0.0% LazyCompile: COMPARE native runtime.js:120
1 0.0% 0.0% LazyCompile: ADD native runtime.js:163
1 0.0% 0.0% LazyCompile: *stylizeNoColor util.js:148
1 0.0% 0.0% LazyCompile: *sto
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualRollingLRS.js:38
1 0.0% 0.0% LazyCompile:
*startup.globalTimeouts.global.clearTimeout node.js:144
1 0.0% 0.0% LazyCompile: *formatValue util.js:153
1 0.0% 0.0% LazyCompile: *exports.warn console.js:32
1 0.0% 0.0% LazyCompile: *cmd.process_packet
/home/chris/CDRReportServer/tags/1.1.0/node_modules/mysql-native/lib/mysql-native/command.js:27
1 0.0% 0.0% LazyCompile: *TxnByTxnStartLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/txnByTxnStartLRS.js:61
1 0.0% 0.0% LazyCompile: *Transport.handleRequest.req
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/transport.js:50
1 0.0% 0.0% LazyCompile: *Socket.dispatch
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/socket.js:228
1 0.0% 0.0% LazyCompile: *OutgoingMessage.write http.js:588
1 0.0% 0.0% LazyCompile: *OutgoingMessage.setHeader
http.js:524
1 0.0% 0.0% LazyCompile:
*MdipSuccessesByTxnStartLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/mdipSuccessesByTxnStartLRS.js:64
1 0.0% 0.0% LazyCompile: *Manager.get
/home/chris/CDRReportServer/tags/1.1.0/node_modules/
socket.io/lib/manager.js:156
1 0.0% 0.0% LazyCompile: *LocalTimezoneString native
date.js:498
1 0.0% 0.0% LazyCompile: *CryptoStream.resume tls.js:161
1 0.0% 0.0% LazyCompile: *ConnectionByNameLRS.augmentRow
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/connectionByNameLRS.js:45
1 0.0% 0.0% LazyCompile: $Array.set_ native v8natives.js:568
1 0.0% 0.0% KeyedStoreIC: args_count: 0 {9}
1 0.0% 0.0% KeyedLoadIC: store
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {8}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {5}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {4}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {3}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {1}
1 0.0% 0.0% KeyedLoadIC: args_count: 0 {10}
1 0.0% 0.0% Function: ~str util.js:328
1 0.0% 0.0% Function: ~sto
/home/chris/CDRReportServer/tags/1.1.0/frontend/lrs/virtualRollingLRS.js:38
1 0.0% 0.0% Function: ~splitPath path.js:265
1 0.0% 0.0% Function: ~require.registerExtension module.js:387
1 0.0% 0.0% Function: ~readPackage module.js:97
1 0.0% 0.0% Function: ~isBuffer buffer.js:288
1 0.0% 0.0% Function: ~fs.lstatSync fs.js:419
1 0.0% 0.0% Function: ~exports.stopProfiling
/home/chris/CDRReportServer/tags/1.1.0/node_modules/v8-profiler/v8-profiler.js:220
1 0.0% 0.0% Function: ~exports.resolve path.js:272
1 0.0% 0.0% Function: ~coerce buffer.js:199
1 0.0% 0.0% Function: ~Stream stream.js:25
1 0.0% 0.0% Function: ~SlowBuffer.slice buffer.js:185
1 0.0% 0.0% Function: ~NativeModule.require node.js:496
1 0.0% 0.0% Function: ~<anonymous> node.js:280
1 0.0% 0.0% Function: ~<anonymous> fs.js:152

[C++]:
ticks total nonlib name

[GC]:
ticks total nonlib name
776 0.6%

[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
111345 91.6% /lib/libc-2.12.1.so

reply | permalink

Related Discussions

Discussion Navigation

view	thread \| post

Discussion Overview

group	nodejs @
categories	nodejs
posted	Oct 4, '12 at 4:22p
active	Mar 14, '14 at 3:30a
posts	5
users	5
website	nodejs.org
irc	#node.js

responses	expanded	Hotkey: s
font	variable	Hotkey: f
user style	avatars	Hotkey: a

[nodejs] Profiling problem, is 91% of ticks in libc 'normal'.

Search Discussions

Related Discussions

5 users in discussion