iojs --prof benchmark/http_simple_auto.js -k -t10 -c100 -n1000000
Run through v8's tools/linux-tick-processor:
(Unpatched io.js 2.x@master)
[JavaScript]:
ticks total nonlib name
146 2.0% 2.7% LazyCompile: *exports._unrefActive timers.js:524:32
140 1.9% 2.6% LazyCompile: *nextTick node.js:466:22
76 1.0% 1.4% LazyCompile: *emit events.js:117:44
62 0.8% 1.1% LazyCompile: *Readable.read _stream_readable.js:246:35
...
[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
1502 20.3% /lib/x86_64-linux-gnu/libpthread-2.21.so
587 39.1% LazyCompile: *Socket._writeGeneric net.js:620:42
587 100.0% LazyCompile: *clearBuffer _stream_writable.js:362:21
587 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
587 100.0% LazyCompile: *<anonymous> /root/io.js/benchmark/http_simple_auto.js:24:41
587 100.0% LazyCompile: *emit events.js:117:44
521 34.7% LazyCompile: *createWriteReq net.js:695:24
521 100.0% LazyCompile: ~Socket._writeGeneric net.js:620:42
424 81.4% LazyCompile: *clearBuffer _stream_writable.js:362:21
424 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
424 100.0% LazyCompile: *<anonymous> /root/io.js/benchmark/http_simple_auto.js:24:41
94 18.0% LazyCompile: *doWrite _stream_writable.js:284:17
94 100.0% LazyCompile: ~clearBuffer _stream_writable.js:362:21
94 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
264 3.6% [vdso]
254 96.2% LazyCompile: *exports._unrefActive timers.js:524:32
122 48.0% LazyCompile: *onread net.js:499:16
71 28.0% LazyCompile: *Socket._writeGeneric net.js:620:42
71 100.0% LazyCompile: *clearBuffer _stream_writable.js:362:21
71 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
71 100.0% LazyCompile: *<anonymous> /root/io.js/benchmark/http_simple_auto.js:24:41
44 17.3% LazyCompile: *unrefTimer net.js:174:51
43 97.7% LazyCompile: ~Socket._writeGeneric net.js:620:42
42 97.7% LazyCompile: *clearBuffer _stream_writable.js:362:21
42 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
1 2.3% LazyCompile: *doWrite _stream_writable.js:284:17
1 100.0% LazyCompile: ~clearBuffer _stream_writable.js:362:21
1 2.3% LazyCompile: ~onread net.js:499:16
17 6.7% LazyCompile: ~unrefTimer net.js:174:51
15 88.2% LazyCompile: ~Socket._writeGeneric net.js:620:42
10 66.7% LazyCompile: *doWrite _stream_writable.js:284:17
10 100.0% LazyCompile: ~clearBuffer _stream_writable.js:362:21
4 26.7% LazyCompile: *clearBuffer _stream_writable.js:362:21
4 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:5
Concurrency Level: 100
Time taken for tests: 9.486 seconds
Complete requests: 50000
Failed requests: 0
Non-2xx responses: 50000
Keep-Alive requests: 50000
Total transferred: 7150000 bytes
HTML transferred: 500000 bytes
Requests per second: 5271.07 [#/sec] (mean)
Time per request: 18.971 [ms] (mean)
Time per request: 0.190 [ms] (mean, across all concurrent requests)
Transfer rate: 736.10 [Kbytes/sec] received
Connection Times (ms)
min mean[+/-sd] median max
Connect: 0 0 0.3 0 11
Processing: 3 19 11.1 16 209
Waiting: 3 19 11.1 16 209
Total: 3 19 11.3 16 213
Percentage of the requests served within a certain time (ms)
50% 16
66% 18
75% 19
80% 20
90% 26
95% 36
98% 47
99% 57
100% 213 (longest request)
Statistical profiling result from ../unsorted1-v8.log, (8577 ticks, 0 unaccounted, 0 excluded).
...
[JavaScript]:
ticks total nonlib name
173 2.0% 2.8% LazyCompile: *nextTick node.js:466:22
103 1.2% 1.7% LazyCompile: *emit events.js:117:44
60 0.7% 1.0% LazyCompile: *Readable.read _stream_readable.js:246:35
58 0.7% 0.9% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
46 0.5% 0.7% LazyCompile: *test native regexp.js:120:20
...
27 0.3% 0.4% LazyCompile: *exports._unrefActive timers.js:582:32
...
[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
1928 22.5% /lib/x86_64-linux-gnu/libpthread-2.21.so
...
321 3.7% [vdso]
306 95.3% LazyCompile: *exports._unrefActive timers.js:582:32
151 49.3% LazyCompile: *onread net.js:499:16
66 21.6% LazyCompile: *Socket._writeGeneric net.js:620:42
66 100.0% LazyCompile: *clearBuffer _stream_writable.js:362:21
66 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
66 100.0% LazyCompile: *<anonymous> /root/io.js/benchmark/http_simple_auto.js:24:41
64 20.9% LazyCompile: *unrefTimer net.js:174:51
64 100.0% LazyCompile: ~Socket._writeGeneric net.js:620:42
63 98.4% LazyCompile: *clearBuffer _stream_writable.js:362:21
63 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
25 8.2% LazyCompile: ~unrefTimer net.js:174:51
23 92.0% LazyCompile: ~Socket._writeGeneric net.js:620:42
17 73.9% LazyCompile: *doWrite _stream_writable.js:284:17
17 100.0% LazyCompile: ~clearBuffer _stream_writable.js:362:21
6 26.1% LazyCompile: *clearBuffer _stream_writable.js:362:21
6 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
2 8.0% LazyCompile: ~onread net.js:499:16
[JavaScript]:
ticks total nonlib name
127 1.8% 2.4% LazyCompile: *nextTick node.js:466:22
68 1.0% 1.3% LazyCompile: *emit events.js:117:44
44 0.6% 0.8% LazyCompile: *exports._unrefActive timers.js:526:32
40 0.6% 0.8% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
38 0.5% 0.7% LazyCompile: *remove internal/heap.js:71:16
36 0.5% 0.7% Stub: StringAddStub
35 0.5% 0.7% LazyCompile: *swap internal/heap.js:173:14
...
11 0.2% 0.2% LazyCompile: *insert internal/heap.js:37:16
...
[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
1525 21.5% /lib/x86_64-linux-gnu/libpthread-2.21.so
881 57.8% LazyCompile: *Socket._writeGeneric net.js:620:42
881 100.0% LazyCompile: *clearBuffer _stream_writable.js:362:21
881 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
881 100.0% LazyCompile: *<anonymous> /root/io.js/benchmark/http_simple_auto.js:24:41
881 100.0% LazyCompile: *emit events.js:117:44
333 21.8% LazyCompile: *createWriteReq net.js:695:24
333 100.0% LazyCompile: ~Socket._writeGeneric net.js:620:42
227 68.2% LazyCompile: *clearBuffer _stream_writable.js:362:21
227 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
227 100.0% LazyCompile: *<anonymous> /root/io.js/benchmark/http_simple_auto.js:24:41
102 30.6% LazyCompile: *doWrite _stream_writable.js:284:17
102 100.0% LazyCompile: ~clearBuffer _stream_writable.js:362:21
102 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
239 3.4% [vdso]
221 92.5% LazyCompile: *exports._unrefActive timers.js:526:32
113 51.1% LazyCompile: *onread net.js:499:16
85 38.5% LazyCompile: *Socket._writeGeneric net.js:620:42
85 100.0% LazyCompile: *clearBuffer _stream_writable.js:362:21
85 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
85 100.0% LazyCompile: *<anonymous> /root/io.js/benchmark/http_simple_auto.js:24:41
15 6.8% LazyCompile: ~unrefTimer net.js:174:51
13 86.7% LazyCompile: ~Socket._writeGeneric net.js:620:42
11 84.6% LazyCompile: *doWrite _stream_writable.js:284:17
11 100.0% LazyCompile: ~clearBuffer _stream_writable.js:362:21
2 15.4% LazyCompile: *clearBuffer _stream_writable.js:362:21
2 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
2 13.3% LazyCompile: ~onread net.js:499:16
8 3.6% LazyCompile: *unrefTimer net.js:174:51
8 100.0% LazyCompile: ~Socket._writeGeneric net.js:620:42
8 100.0% LazyCompile: *clearBuffer _stream_writable.js:362:21
8 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
8 3.3% v8::internal::Runtime_CompileLazy(int, v8::internal::Object**, v8::internal::Isolate*)
Using the test described in https://github.com/joyent/node/wiki/Optimizing-_unrefActive#how-to-reproduce-it
Run against wrk -t12 -c400 -d30s http://127.0.0.1:4242/
wrk -t12 -c400 -d30s http://127.0.0.1:4242/
Running 30s test @ http://127.0.0.1:4242/
12 threads and 400 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 53.55ms 9.11ms 320.17ms 91.22%
Req/Sec 606.45 112.09 1.42k 82.63%
217462 requests in 30.07s, 20.53MB read
Requests/sec: 7232.83
Transfer/sec: 699.27KB
[JavaScript]:
ticks total nonlib name
2842 10.5% 14.8% LazyCompile: *exports._unrefActive timers.js:524:32
1146 4.2% 6.0% Stub: CompareICStub {1}
393 1.4% 2.1% LazyCompile: *emit events.js:117:44
380 1.4% 2.0% LazyCompile: *nextTick node.js:466:22
...
[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
2842 10.5% LazyCompile: *exports._unrefActive timers.js:524:32
1365 48.0% LazyCompile: *onread net.js:499:16
1362 47.9% LoadPolymorphicIC: _idlePrev {3}
1362 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
1356 99.6% LazyCompile: *OutgoingMessage._send _http_outgoing.js:110:43
1356 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
1356 100.0% LazyCompile: *<anonymous> /root/test.js:2:41
80 2.8% LazyCompile: *unrefTimer net.js:174:51
75 93.8% LazyCompile: ~Socket._writeGeneric net.js:620:42
75 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
75 100.0% LazyCompile: *Writable.write _stream_writable.js:186:36
75 100.0% LazyCompile: *Socket.write net.js:613:34
5 6.3% LazyCompile: ~onread net.js:499:16
1301 4.8% [vdso]
1292 99.3% LazyCompile: *exports._unrefActive timers.js:524:32
632 48.9% LoadPolymorphicIC: _idlePrev {3}
632 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
623 98.6% LazyCompile: *OutgoingMessage._send _http_outgoing.js:110:43
623 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
599 46.4% LazyCompile: *onread net.js:499:16
45 3.5% LazyCompile: *unrefTimer net.js:174:51
45 100.0% LazyCompile: ~Socket._writeGeneric net.js:620:42
45 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
45 100.0% LazyCompile: *Writable.write _stream_writable.js:186:36
1146 4.2% Stub: CompareICStub {1}
1146 100.0% LazyCompile: *exports._unrefActive timers.js:524:32
577 50.3% LazyCompile: *onread net.js:499:16
534 46.6% LoadPolymorphicIC: _idlePrev {3}
534 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
531 99.4% LazyCompile: *OutgoingMessage._send _http_outgoing.js:110:43
531 100.0% LazyCompile: *OutgoingMessage.end _http_outgoing.js:507:41
33 2.9% LazyCompile: *unrefTimer net.js:174:51
32 97.0% LazyCompile: ~Socket._writeGeneric net.js:620:42
32 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
32 100.0% LazyCompile: *Writable.write _stream_writable.js:186:36
1 3.0% LazyCompile: ~onread net.js:499:16
wrk -t12 -c400 -d30s http://127.0.0.1:4242/
Running 30s test @ http://127.0.0.1:4242/
12 threads and 400 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 54.40ms 20.70ms 350.26ms 85.29%
Req/Sec 603.08 206.94 1.57k 65.38%
213706 requests in 30.06s, 20.18MB read
Requests/sec: 7108.85
Transfer/sec: 687.28KB
[JavaScript]:
ticks total nonlib name
511 1.9% 3.0% LazyCompile: *nextTick node.js:466:22
361 1.4% 2.1% LazyCompile: *emit events.js:117:44
226 0.9% 1.3% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
167 0.6% 1.0% Stub: MegamorphicLoadStub
164 0.6% 1.0% LazyCompile: *exports._unrefActive timers.js:582:32
...
[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
7253 27.5% /lib/x86_64-linux-gnu/libpthread-2.21.so
4504 62.1% LazyCompile: *Socket._writeGeneric net.js:620:42
...
1370 5.2% [vdso]
1362 99.4% LazyCompile: *exports._unrefActive timers.js:582:32
684 50.2% LazyCompile: *onread net.js:499:16
554 40.7% LazyCompile: *Socket._writeGeneric net.js:620:42
554 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
554 100.0% LazyCompile: *OutgoingMessage._writeRaw _http_outgoing.js:130:47
554 100.0% LazyCompile: *OutgoingMessage._send _http_outgoing.js:110:43
110 8.1% LazyCompile: *unrefTimer net.js:174:51
109 99.1% LazyCompile: ~Socket._writeGeneric net.js:620:42
109 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
63 57.8% LazyCompile: *OutgoingMessage._writeRaw _http_outgoing.js:130:47
46 42.2% LazyCompile: *Writable.write _stream_writable.js:186:36
wrk -t12 -c400 -d30s http://127.0.0.1:4242/
Running 30s test @ http://127.0.0.1:4242/
12 threads and 400 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 45.27ms 8.96ms 320.98ms 91.94%
Req/Sec 720.80 158.52 1.75k 77.57%
256877 requests in 30.08s, 24.25MB read
Requests/sec: 8540.85
Transfer/sec: 825.73KB
[JavaScript]:
ticks total nonlib name
446 1.6% 2.5% LazyCompile: *nextTick node.js:466:22
430 1.6% 2.4% LazyCompile: *remove internal/heap.js:71:16
406 1.5% 2.3% LazyCompile: *emit events.js:117:44
259 0.9% 1.5% LazyCompile: *swap internal/heap.js:173:14
199 0.7% 1.1% LazyCompile: *Readable.read _stream_readable.js:246:35
181 0.7% 1.0% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
178 0.6% 1.0% LazyCompile: *parserOnIncoming _http_server.js:401:28
171 0.6% 1.0% LazyCompile: *_tickCallback node.js:324:27
...
148 0.5% 0.8% LazyCompile: *exports._unrefActive timers.js:526:32
...
[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
1504 5.5% [vdso]
1481 98.5% LazyCompile: *exports._unrefActive timers.js:526:32
713 48.1% LazyCompile: *Socket._writeGeneric net.js:620:42
713 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
713 100.0% LazyCompile: *OutgoingMessage._writeRaw _http_outgoing.js:130:47
713 100.0% LazyCompile: *OutgoingMessage._send _http_outgoing.js:110:43
692 46.7% LazyCompile: *onread net.js:499:16
75 5.1% LazyCompile: *unrefTimer net.js:174:51
75 100.0% LazyCompile: ~Socket._writeGeneric net.js:620:42
75 100.0% LazyCompile: *writeOrBuffer _stream_writable.js:255:23
40 53.3% LazyCompile: *Writable.write _stream_writable.js:186:36
35 46.7% LazyCompile: *OutgoingMessage._writeRaw _http_outgoing.js:130:47
var http = require('http');
var reqIndex = 0;
var server = http.createServer(function (req, res) {
reqIndex++;
req.setTimeout(reqIndex, function() { });
});
server.listen(4242);Using the second test as above and descibed here, run against wrk -t12 -c10000 -d30s http://127.0.0.1:4242/
[JavaScript]:
ticks total nonlib name
1826 16.8% 17.6% LazyCompile: *exports._unrefActive timers.js:524:32
52 0.5% 0.5% LazyCompile: *emit events.js:117:44
34 0.3% 0.3% LazyCompile: *addListener events.js:191:58
...
[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
6194 57.1% syscall
1826 16.8% LazyCompile: *exports._unrefActive timers.js:524:32
606 33.2% LazyCompile: *onread net.js:499:16
603 33.0% LazyCompile: *connectionListener _http_server.js:252:28
539 89.4% LazyCompile: *emit events.js:117:44
539 100.0% LazyCompile: *onconnection net.js:1378:22
33 5.5% LazyCompile: *emitOne events.js:75:17
33 100.0% LazyCompile: ~emit events.js:117:44
33 100.0% LazyCompile: *onconnection net.js:1378:22
31 5.1% LazyCompile: ~emitOne events.js:75:17
31 100.0% LazyCompile: ~emit events.js:117:44
31 100.0% LazyCompile: *onconnection net.js:1378:22
557 30.5% LazyCompile: *<anonymous> /root/test3.js:4:41
515 92.5% LazyCompile: *emit events.js:117:44
515 100.0% LazyCompile: ~parserOnIncoming _http_server.js:401:28
482 93.6% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
482 100.0% node::Parser::Execute(v8::FunctionCallbackInfo<v8::Value> const&)
33 6.4% LazyCompile: ~parserOnHeadersComplete _http_common.js:42:33
33 100.0% node::Parser::Execute(v8::FunctionCallbackInfo<v8::Value> const&)
42 7.5% LazyCompile: ~emitTwo events.js:85:17
42 100.0% LazyCompile: ~emit events.js:117:44
42 100.0% LazyCompile: ~parserOnIncoming _http_server.js:401:28
42 100.0% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
46 2.5% LazyCompile: *Socket.setTimeout net.js:298:39
46 100.0% LazyCompile: ~connectionListener _http_server.js:252:28
38 82.6% LazyCompile: *emit events.js:117:44
38 100.0% LazyCompile: *onconnection net.js:1378:22
4 8.7% LazyCompile: ~emitOne events.js:75:17
4 100.0% LazyCompile: ~emit events.js:117:44
4 100.0% LazyCompile: *onconnection net.js:1378:22
4 8.7% LazyCompile: *emitOne events.js:75:17
4 100.0% LazyCompile: ~emit events.js:117:44
4 100.0% LazyCompile: *onconnection net.js:1378:22
Statistical profiling result from ../unsorted2-v8.log, (26391 ticks, 0 unaccounted, 0 excluded).
...
[JavaScript]:
ticks total nonlib name
770 7.6% 7.9% LazyCompile: *unrefTimeout timers.js:514:22
52 0.5% 0.5% LazyCompile: *emit events.js:117:44
44 0.4% 0.5% LazyCompile: *addListener events.js:191:58
26 0.3% 0.3% Stub: MegamorphicLoadStub
22 0.2% 0.2% LazyCompile: *exports._unrefActive timers.js:582:32
15 0.1% 0.2% LazyCompile: *Readable.on _stream_readable.js:650:33
14 0.1% 0.1% Stub: InstanceofStub
14 0.1% 0.1% LazyCompile: *Readable.read _stream_readable.js:246:35
12 0.1% 0.1% LazyCompile: _makeTimerTimeout timers.js:480:27
...
[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
6181 60.6% syscall
770 7.6% LazyCompile: *unrefTimeout timers.js:514:22
236 2.3% node::HandleWrap::Close(v8::FunctionCallbackInfo<v8::Value> const&)
236 100.0% v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*)
236 100.0% LazyCompile: ~Socket._destroy net.js:435:37
232 98.3% LazyCompile: *Socket.destroy net.js:491:36
232 100.0% LazyCompile: ~<anonymous> _http_server.js:285:32
206 88.8% LazyCompile: *emit events.js:117:44
26 11.2% LazyCompile: ~emitNone events.js:65:18
209 2.1% [vdso]
79 37.8% LazyCompile: *exports._unrefActive timers.js:582:32
36 45.6% LazyCompile: *connectionListener _http_server.js:252:28
24 66.7% LazyCompile: *emit events.js:117:44
24 100.0% LazyCompile: *onconnection net.js:1378:22
8 22.2% LazyCompile: *emitOne events.js:75:17
8 100.0% LazyCompile: ~emit events.js:117:44
8 100.0% LazyCompile: *onconnection net.js:1378:22
4 11.1% LazyCompile: ~emitOne events.js:75:17
4 100.0% LazyCompile: ~emit events.js:117:44
4 100.0% LazyCompile: *onconnection net.js:1378:22
24 30.4% LazyCompile: *<anonymous> /root/test3.js:4:41
19 79.2% LazyCompile: *emit events.js:117:44
19 100.0% LazyCompile: ~parserOnIncoming _http_server.js:401:28
19 100.0% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
5 20.8% LazyCompile: ~emitTwo events.js:85:17
5 100.0% LazyCompile: ~emit events.js:117:44
5 100.0% LazyCompile: ~parserOnIncoming _http_server.js:401:28
17 21.5% LazyCompile: *onread net.js:499:16
2 2.5% LazyCompile: *Socket.setTimeout net.js:298:39
2 100.0% LazyCompile: ~connectionListener _http_server.js:252:28
1 50.0% LazyCompile: ~emitOne events.js:75:17
1 100.0% LazyCompile: ~emit events.js:117:44
1 50.0% LazyCompile: *emitOne events.js:75:17
1 100.0% LazyCompile: ~emit events.js:117:44
37 17.7% LazyCompile: *unrefTimeout timers.js:514:22
25 12.0% v8::internal::Runtime_CompileLazy(int, v8::internal::Object**, v8::internal::Isolate*)
6 24.0% LazyCompile: *emit events.js:117:44
3 50.0% LazyCompile: ~<anonymous> net.js:466:32
3 50.0% LazyCompile: *Socket._onTimeout net.js:315:39
3 100.0% LazyCompile: _makeTimerTimeout timers.js:480:27
3 100.0% LazyCompile: *unrefTimeout timers.js:514:22
[JavaScript]:
ticks total nonlib name
51 0.5% 0.5% LazyCompile: *emit events.js:117:44
49 0.5% 0.5% LazyCompile: *remove internal/heap.js:71:16
37 0.4% 0.4% LazyCompile: *swap internal/heap.js:173:14
29 0.3% 0.3% LazyCompile: *addListener events.js:191:58
...
[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.
(NOTE: Nothing relevant here, but shown for posterity.)
ticks parent name
7095 70.8% syscall
215 2.1% node::HandleWrap::Close(v8::FunctionCallbackInfo<v8::Value> const&)
212 98.6% v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*)
212 100.0% LazyCompile: ~Socket._destroy net.js:435:37
212 100.0% LazyCompile: *Socket.destroy net.js:491:36
212 100.0% LazyCompile: ~<anonymous> _http_server.js:285:32
199 93.9% LazyCompile: *emit events.js:117:44
13 6.1% LazyCompile: ~emitNone events.js:65:18
var http = require('http');
var server = http.createServer(function (req, res) {
var rand = (Math.random() * 100) >> 0;
var timeout = rand % 5 === 0 ? 10 : 10000 + rand;
req.setTimeout(timeout, function() { });
});
server.listen(4242, function() {
console.log('Server listening on port 4242...');
});My attempt at something potentially even worse performing on timeout than benchmark #3. Run against wrk -t12 -c10000 -d60s http://127.0.0.1:4242/
Running 1m test @ http://127.0.0.1:4242/
12 threads and 10000 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 0.00us 0.00us 0.00us -nan%
Req/Sec 0.00 0.00 0.00 -nan%
0 requests in 1.00m, 0.00B read
Socket errors: connect 0, read 4305, write 0, timeout 0
Requests/sec: 0.00
Transfer/sec: 0.00B
Statistical profiling result from ../dunno4-v8.log, (9005 ticks, 0 unaccounted, 0 excluded).
...
[JavaScript]:
ticks total nonlib name
2864 31.8% 33.3% LazyCompile: *exports._unrefActive timers.js:524:32
50 0.6% 0.6% LazyCompile: *emit events.js:117:44
39 0.4% 0.5% LazyCompile: *addListener events.js:191:58
34 0.4% 0.4% Stub: MegamorphicLoadStub
...
[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
3231 35.9% syscall
2864 31.8% LazyCompile: *exports._unrefActive timers.js:524:32
1040 36.3% LazyCompile: *onread net.js:499:16
923 32.2% LazyCompile: *connectionListener _http_server.js:252:28
862 93.4% LazyCompile: *emit events.js:117:44
862 100.0% LazyCompile: *onconnection net.js:1378:22
41 4.4% LazyCompile: *emitOne events.js:75:17
41 100.0% LazyCompile: ~emit events.js:117:44
41 100.0% LazyCompile: *onconnection net.js:1378:22
20 2.2% LazyCompile: ~emitOne events.js:75:17
20 100.0% LazyCompile: ~emit events.js:117:44
20 100.0% LazyCompile: *onconnection net.js:1378:22
760 26.5% LazyCompile: *<anonymous> /root/test4.js:3:41
727 95.7% LazyCompile: *emit events.js:117:44
727 100.0% LazyCompile: ~parserOnIncoming _http_server.js:401:28
677 93.1% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
Running 1m test @ http://127.0.0.1:4242/
12 threads and 10000 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 0.00us 0.00us 0.00us -nan%
Req/Sec 0.00 0.00 0.00 -nan%
0 requests in 1.00m, 0.00B read
Socket errors: connect 0, read 2976, write 0, timeout 0
Requests/sec: 0.00
Transfer/sec: 0.00B
Statistical profiling result from ../unsorted4-v8.log, (6883 ticks, 5 unaccounted, 0 excluded).
...
[JavaScript]:
ticks total nonlib name
529 7.7% 8.4% LazyCompile: *unrefTimeout timers.js:514:22
64 0.9% 1.0% LazyCompile: *addListener events.js:191:58
44 0.6% 0.7% LazyCompile: *emit events.js:117:44
32 0.5% 0.5% LazyCompile: *connectionListener _http_server.js:252:28
30 0.4% 0.5% Stub: MegamorphicLoadStub
24 0.3% 0.4% LazyCompile: *nextTick node.js:466:22
22 0.3% 0.3% LazyCompile: *ReadableState _stream_readable.js:15:23
21 0.3% 0.3% LazyCompile: *Readable.on _stream_readable.js:650:33
20 0.3% 0.3% LazyCompile: *exports._unrefActive timers.js:582:32
...
8 0.1% 0.1% LazyCompile: _makeTimerTimeout timers.js:480:27
...
[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
2074 30.1% syscall
529 7.7% LazyCompile: *unrefTimeout timers.js:514:22
336 4.9% node::HandleWrap::Close(v8::FunctionCallbackInfo<v8::Value> const&)
332 98.8% v8::internal::Builtin_HandleApiCall(int, v8::internal::Object**, v8::internal::Isolate*)
332 100.0% LazyCompile: ~Socket._destroy net.js:435:37
326 98.2% LazyCompile: *Socket.destroy net.js:491:36
326 100.0% LazyCompile: ~<anonymous> _http_server.js:285:32
318 97.5% LazyCompile: *emit events.js:117:44
8 2.5% LazyCompile: ~emitNone events.js:65:18
215 3.1% [vdso]
149 69.3% LazyCompile: *exports._unrefActive timers.js:582:32
50 33.6% LazyCompile: *onread net.js:499:16
48 32.2% LazyCompile: *connectionListener _http_server.js:252:28
41 85.4% LazyCompile: *emit events.js:117:44
41 100.0% LazyCompile: *onconnection net.js:1378:22
5 10.4% LazyCompile: *emitOne events.js:75:17
5 100.0% LazyCompile: ~emit events.js:117:44
5 100.0% LazyCompile: *onconnection net.js:1378:22
2 4.2% LazyCompile: ~emitOne events.js:75:17
2 100.0% LazyCompile: ~emit events.js:117:44
2 100.0% LazyCompile: *onconnection net.js:1378:22
41 27.5% LazyCompile: *<anonymous> /root/test4.js:3:41
35 85.4% LazyCompile: *emit events.js:117:44
35 100.0% LazyCompile: ~parserOnIncoming _http_server.js:401:28
34 97.1% LazyCompile: *parserOnHeadersComplete _http_common.js:42:33
Running 1m test @ http://127.0.0.1:4242/
12 threads and 10000 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 0.00us 0.00us 0.00us -nan%
Req/Sec 0.00 0.00 0.00 -nan%
0 requests in 1.00m, 0.00B read
Socket errors: connect 0, read 2543, write 0, timeout 0
Requests/sec: 0.00
Transfer/sec: 0.00B
Statistical profiling result from ../heap4-v8.log, (5330 ticks, 1 unaccounted, 0 excluded).
...
[JavaScript]:
ticks total nonlib name
62 1.2% 1.2% LazyCompile: *remove internal/heap.js:71:16
59 1.1% 1.2% LazyCompile: *swap internal/heap.js:173:14
36 0.7% 0.7% LazyCompile: *emit events.js:117:44
36 0.7% 0.7% LazyCompile: *addListener events.js:191:58
25 0.5% 0.5% Stub: MegamorphicLoadStub
20 0.4% 0.4% LazyCompile: *insert internal/heap.js:37:16
20 0.4% 0.4% LazyCompile: *exports._unrefActive timers.js:526:32
19 0.4% 0.4% Stub: CEntryStub
17 0.3% 0.3% LazyCompile: *Readable.on _stream_readable.js:650:33
...
6 0.1% 0.1% LazyCompile: unrefTimeout timers.js:483:22
...
2 0.0% 0.0% LazyCompile: *compareTimer timers.js:603:22