Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
perf(lexer): extract token emission into separate method
As you can see, I also tried to simplify the AST post-processing by
removing explicit TS type annotations in favor of TSDoc comments, but
sadly, `tsc` won't read from those, complaining about implicit `any`
types:
- https://github.com/microsoft/TypeScript/issues/9694
I tried this historically too, and forgot about it, but yeah, it still
doesn't work.
Anyway, numbers (best of 3)...
Before:
$ node lib/benchmark-static-lexer.js
Read 5160 bytes
┌─────────┬────────────┬───────────┬───────────┬───────────┬──────────────┐
│ (index) │ rss │ heapTotal │ heapUsed │ external │ arrayBuffers │
├─────────┼────────────┼───────────┼───────────┼───────────┼──────────────┤
│ start │ '26.78 MB' │ '5.86 MB' │ '5.22 MB' │ '0.35 MB' │ '0.05 MB' │
│ warm-up │ '35.89 MB' │ '7.36 MB' │ '5.16 MB' │ '0.32 MB' │ '0.02 MB' │
│ finish │ '35.90 MB' │ '7.36 MB' │ '5.55 MB' │ '0.32 MB' │ '0.02 MB' │
└─────────┴────────────┴───────────┴───────────┴───────────┴──────────────┘
Warm-up: 733.6131200045347ms
Test: 709.1680589914322ms
After:
$ node lib/benchmark-static-lexer.js
Read 5160 bytes
┌─────────┬────────────┬───────────┬───────────┬───────────┬──────────────┐
│ (index) │ rss │ heapTotal │ heapUsed │ external │ arrayBuffers │
├─────────┼────────────┼───────────┼───────────┼───────────┼──────────────┤
│ start │ '26.78 MB' │ '5.86 MB' │ '5.21 MB' │ '0.34 MB' │ '0.04 MB' │
│ warm-up │ '34.78 MB' │ '7.36 MB' │ '5.14 MB' │ '0.32 MB' │ '0.02 MB' │
│ finish │ '34.79 MB' │ '7.36 MB' │ '5.50 MB' │ '0.32 MB' │ '0.02 MB' │
└─────────┴────────────┴───────────┴───────────┴───────────┴──────────────┘
Warm-up: 667.0908890068531ms
Test: 651.192603006959ms
Reference:
$ node lib/benchmark-reference-lexer.js
Read 5160 bytes
┌─────────┬────────────┬────────────┬───────────┬───────────┬──────────────┐
│ (index) │ rss │ heapTotal │ heapUsed │ external │ arrayBuffers │
├─────────┼────────────┼────────────┼───────────┼───────────┼──────────────┤
│ start │ '36.47 MB' │ '10.86 MB' │ '6.75 MB' │ '0.44 MB' │ '0.05 MB' │
│ warm-up │ '44.52 MB' │ '15.61 MB' │ '7.79 MB' │ '0.42 MB' │ '0.03 MB' │
│ finish │ '52.53 MB' │ '23.61 MB' │ '9.75 MB' │ '0.42 MB' │ '0.03 MB' │
└─────────┴────────────┴────────────┴───────────┴───────────┴──────────────┘
Warm-up: 716.122205004096ms
Test: 678.240804001689ms
ie. we're finally beating the reference lexer, and this commit improves
perf by 8.1%.
To know why we might look at the optimization output:
Before:
$ node --trace-opt --trace-deopt-verbose lib/benchmark-static-lexer.js
Read 5160 bytes
[marking 0x176199d66181 <JSFunction next (sfi = 0x1761244d61e9)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x176199d66181 <JSFunction next (sfi = 0x1761244d61e9)> (target TURBOFAN) using TurboFan]
[marking 0x176199d65fc1 <JSFunction Token (sfi = 0x1761244d8891)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: small function]
[compiling method 0x176199d65fc1 <JSFunction Token (sfi = 0x1761244d8891)> (target TURBOFAN) using TurboFan]
[optimizing 0x1761c8e84279 <JSFunction Token (sfi = 0x1761244d8891)> (target TURBOFAN) - took 0.013, 1.708, 0.024 ms]
[completed optimizing 0x1761c8e84279 <JSFunction Token (sfi = 0x1761244d8891)> (target TURBOFAN)]
[marking 0x1761c8e82b09 <JSFunction lex (sfi = 0x1761244d60f9)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x1761c8e82b09 <JSFunction lex (sfi = 0x1761244d60f9)> (target TURBOFAN) using TurboFan]
[optimizing 0x1761c8e82b09 <JSFunction lex (sfi = 0x1761244d60f9)> (target TURBOFAN) - took 0.006, 1.804, 0.038 ms]
[completed optimizing 0x1761c8e82b09 <JSFunction lex (sfi = 0x1761244d60f9)> (target TURBOFAN)]
[marking 0x1761c8e84071 <JSFunction test (sfi = 0x1761244d9a79)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x1761b1504841 <JSFunction test (sfi = 0x1761244d9a79)> (target TURBOFAN) using TurboFan OSR]
[optimizing 0x1761b1504841 <JSFunction test (sfi = 0x1761244d9a79)> (target TURBOFAN) - took 0.007, 1.708, 0.030 ms]
[optimizing 0x1761b1504751 <JSFunction next (sfi = 0x1761244d61e9)> (target TURBOFAN) - took 0.031, 17.427, 0.061 ms]
[completed optimizing 0x1761b1504751 <JSFunction next (sfi = 0x1761244d61e9)> (target TURBOFAN)]
[marking 0x1761b1504841 <JSFunction test (sfi = 0x1761244d9a79)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[found optimized code for 0x1761b1504841 <JSFunction test (sfi = 0x1761244d9a79)> (target TURBOFAN) at OSR bytecode offset 139]
After:
$ node --trace-opt --trace-deopt-verbose lib/benchmark-static-lexer.js
Read 5160 bytes
[marking 0x3e0f76ca5489 <JSFunction next (sfi = 0x3e0fd2616241)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x3e0f76ca5489 <JSFunction next (sfi = 0x3e0fd2616241)> (target TURBOFAN) using TurboFan]
[marking 0x3e0f76ca5451 <JSFunction emit (sfi = 0x3e0fd26161f1)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: small function]
[compiling method 0x3e0f76ca5451 <JSFunction emit (sfi = 0x3e0fd26161f1)> (target TURBOFAN) using TurboFan]
[optimizing 0x3e0f76ca5451 <JSFunction emit (sfi = 0x3e0fd26161f1)> (target TURBOFAN) - took 0.012, 1.221, 0.042 ms]
[completed optimizing 0x3e0f76ca5451 <JSFunction emit (sfi = 0x3e0fd26161f1)> (target TURBOFAN)]
[marking 0x3e0f74043ff1 <JSFunction lex (sfi = 0x3e0fd2616101)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x3e0f74043ff1 <JSFunction lex (sfi = 0x3e0fd2616101)> (target TURBOFAN) using TurboFan]
[optimizing 0x3e0f74043ff1 <JSFunction lex (sfi = 0x3e0fd2616101)> (target TURBOFAN) - took 0.006, 1.335, 0.024 ms]
[completed optimizing 0x3e0f74043ff1 <JSFunction lex (sfi = 0x3e0fd2616101)> (target TURBOFAN)]
[marking 0x3e0f740440a9 <JSFunction test (sfi = 0x3e0fd26199a9)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[compiling method 0x3e0f83dc3f29 <JSFunction test (sfi = 0x3e0fd26199a9)> (target TURBOFAN) using TurboFan OSR]
[optimizing 0x3e0f83dc3f29 <JSFunction test (sfi = 0x3e0fd26199a9)> (target TURBOFAN) - took 0.006, 1.951, 0.054 ms]
[optimizing 0x3e0f83dc3e39 <JSFunction next (sfi = 0x3e0fd2616241)> (target TURBOFAN) - took 0.033, 14.472, 0.064 ms]
[completed optimizing 0x3e0f83dc3e39 <JSFunction next (sfi = 0x3e0fd2616241)> (target TURBOFAN)]
[marking 0x3e0f83dc3f29 <JSFunction test (sfi = 0x3e0fd26199a9)> for optimization to TURBOFAN, ConcurrencyMode::kConcurrent, reason: hot and stable]
[found optimized code for 0x3e0f83dc3f29 <JSFunction test (sfi = 0x3e0fd26199a9)> (target TURBOFAN) at OSR bytecode offset 139]
What's happening in there?
- Both start by compiling `next()` ("hot and stable").
- The old code then compiles `Token()` ("small function") and optimizes
it.
- In contrast new code compiles `emit()` ("small function") and
optimizes it.
- It never looks at `Token()` (presumably that gets inlined).
- Both then compile `lex()` ("hot and stable").
- Both the optimize `lex()`.
- Old code compiles `test()`, optimizes `test()`, optimizes `next()`.
- Old code finished by optimizing `test()`.
Caveat: this is happening over a single run and letting either of these
run with higher `DEFAULT_ITERATIONS` might allow more optimizations to
eventually occur.
Evidently, the value of optimizing `emit()` way outweighs that of
optimizing `Token()`. We could look at JITed code to get a better idea
of what's going on here if we had the time.
We can also run `yarn profile:static:lexer` to compare where time is
being spent, although to be honest, the output is too verbose and I
can't see any smoking guns in here:
Before:
$ node --trace-warnings --prof --no-logfile-per-isolate lib/benchmark-static-lexer.js && node --prof-process v8.log
Read 5160 bytes
┌─────────┬────────────┬───────────┬───────────┬───────────┬──────────────┐
│ (index) │ rss │ heapTotal │ heapUsed │ external │ arrayBuffers │
├─────────┼────────────┼───────────┼───────────┼───────────┼──────────────┤
│ start │ '28.06 MB' │ '6.11 MB' │ '5.46 MB' │ '0.35 MB' │ '0.05 MB' │
│ warm-up │ '36.94 MB' │ '7.61 MB' │ '5.44 MB' │ '0.32 MB' │ '0.02 MB' │
│ finish │ '36.95 MB' │ '7.61 MB' │ '5.89 MB' │ '0.32 MB' │ '0.02 MB' │
└─────────┴────────────┴───────────┴───────────┴───────────┴──────────────┘
Warm-up: 36.8138709962368ms
Test: 7.950203999876976ms
(node:75930) ExperimentalWarning: VM Modules is an experimental feature. This feature could change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
Statistical profiling result from v8.log, (169 ticks, 4 unaccounted, 0 excluded).
[Shared libraries]:
ticks total nonlib name
25 14.8% /usr/lib/system/libsystem_pthread.dylib
16 9.5% /usr/lib/system/libsystem_c.dylib
7 4.1% /usr/lib/libc++.1.dylib
6 3.6% /usr/lib/system/libsystem_kernel.dylib
4 2.4% /usr/lib/system/libsystem_platform.dylib
[JavaScript]:
ticks total nonlib name
8 4.7% 7.2% LazyCompile: *next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:21:9
4 2.4% 3.6% Function: ^next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:21:9
2 1.2% 1.8% LazyCompile: *lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
[C++]:
ticks total nonlib name
40 23.7% 36.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
31 18.3% 27.9% T node::native_module::NativeModuleEnv::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
11 6.5% 9.9% T _host_request_notification
2 1.2% 1.8% t std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> > std::__1::__pad_and_output<char, std::__1::char_traits<char> >(std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> >, char const*, char const*, char const*, std::__1::ios_base&, char)
2 1.2% 1.8% t std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::__put_character_sequence<char, std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*, unsigned long)
2 1.2% 1.8% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
1 0.6% 0.9% t node::fs::ReadLink(v8::FunctionCallbackInfo<v8::Value> const&)
1 0.6% 0.9% t node::fs::Open(v8::FunctionCallbackInfo<v8::Value> const&)
1 0.6% 0.9% T node::binding::GetInternalBinding(v8::FunctionCallbackInfo<v8::Value> const&)
1 0.6% 0.9% T _shm_open
1 0.6% 0.9% T _mach_msg_destroy
[Summary]:
ticks total nonlib name
14 8.3% 12.6% JavaScript
93 55.0% 83.8% C++
3 1.8% 2.7% GC
58 34.3% Shared libraries
4 2.4% Unaccounted
[C++ entry points]:
ticks cpp total name
123 100.0% 72.8% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
[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 1.0% are not shown.
ticks parent name
40 23.7% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
19 47.5% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 10.5% LazyCompile: ~WriteStream node:tty:84:21
2 100.0% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
2 100.0% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:136:19
2 100.0% LazyCompile: ~get node:internal/console/constructor:203:14
2 10.5% Function: ^test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
2 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 5.3% LazyCompile: ~value node:internal/console/constructor:223:20
1 100.0% LazyCompile: ~initializeGlobalConsole node:internal/console/constructor:672:33
1 100.0% LazyCompile: ~patchProcessObject node:internal/bootstrap/pre_execution:102:28
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 5.3% LazyCompile: ~strEscape node:internal/util/inspect:475:19
1 100.0% LazyCompile: ~formatPrimitive node:internal/util/inspect:1519:25
1 100.0% LazyCompile: ~formatValue node:internal/util/inspect:745:21
1 100.0% LazyCompile: ~inspect node:internal/util/inspect:292:17
1 5.3% LazyCompile: ~setupFetch node:internal/bootstrap/pre_execution:176:20
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 5.3% LazyCompile: ~realpathSync node:fs:2439:22
1 100.0% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:394:20
1 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:495:28
1 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
1 5.3% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 5.3% LazyCompile: ~lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 5.3% LazyCompile: ~initializeGlobalConsole node:internal/console/constructor:672:33
1 100.0% LazyCompile: ~patchProcessObject node:internal/bootstrap/pre_execution:102:28
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 5.3% LazyCompile: ~get /Users/wincent/code/masochist-experimental/packages/lexer/lib/index.js:8:77
1 100.0% Function: ~<anonymous> /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-static-lexer.js:1:1
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1059:37
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1114:37
1 5.3% LazyCompile: ~compileFunction node:vm:308:25
1 100.0% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1017:18
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1059:37
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1114:37
1 5.3% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 100.0% Function: ~<anonymous> node:internal/modules/esm/get_format:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 5.3% LazyCompile: ~afterWriteDispatched node:internal/stream_base_commons:155:30
1 100.0% LazyCompile: ~writeGeneric node:internal/stream_base_commons:147:22
1 100.0% LazyCompile: ~Socket._writeGeneric node:net:797:42
1 100.0% LazyCompile: ~Socket._write node:net:834:35
1 5.3% LazyCompile: ~EventEmitterMixin node:internal/event_target:958:27
1 100.0% Function: ~<anonymous> node:internal/fs/promises:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 5.3% Function: ~<anonymous> node:internal/modules/cjs/loader:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 100.0% LazyCompile: ~initializeCJSLoader node:internal/bootstrap/pre_execution:514:29
1 5.3% Function: ~<anonymous> node:internal/fs/rimraf:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 100.0% Function: ~<anonymous> node:internal/fs/promises:1:1
1 5.3% Function: ~<anonymous> /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:1:1
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1059:37
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1114:37
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:969:33
2 5.0% LazyCompile: *lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 50.0% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 50.0% Function: ^test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 5.0% Function: ^next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:21:9
2 100.0% LazyCompile: ~lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
2 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
2 5.0% Function: ^lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% Function: ^test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
2 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 2.5% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 2.5% LazyCompile: ~nextTick node:internal/process/task_queues:103:18
1 100.0% LazyCompile: ~onwrite node:internal/streams/writable:426:17
1 100.0% LazyCompile: ~afterWriteDispatched node:internal/stream_base_commons:155:30
1 100.0% LazyCompile: ~writeGeneric node:internal/stream_base_commons:147:22
1 100.0% LazyCompile: ~Socket._writeGeneric node:net:797:42
1 2.5% LazyCompile: ~lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 2.5% LazyCompile: *next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:21:9
1 100.0% LazyCompile: *lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 2.5% Function: ^Token /Users/wincent/code/masochist-experimental/packages/lexer/lib/Token.js:4:16
1 100.0% Function: ^next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:21:9
1 100.0% LazyCompile: ~lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
31 18.3% T node::native_module::NativeModuleEnv::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
31 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
28 90.3% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
25 89.3% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
5 20.0% Function: ~<anonymous> node:internal/modules/esm/fetch_module:1:1
5 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
4 16.0% LazyCompile: ~initializeCJSLoader node:internal/bootstrap/pre_execution:514:29
4 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
4 16.0% Function: ~<anonymous> node:internal/modules/esm/loader:1:1
4 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
3 12.0% Function: ~<anonymous> node:internal/process/esm_loader:1:1
3 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
3 12.0% Function: ~<anonymous> node:internal/modules/esm/get_source:1:1
3 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 4.0% LazyCompile: ~initializeSourceMapsHandlers node:internal/bootstrap/pre_execution:553:38
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 4.0% Function: ~<anonymous> node:internal/source_map/source_map_cache:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 4.0% Function: ~<anonymous> node:internal/modules/esm/resolve:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 4.0% Function: ~<anonymous> node:internal/modules/esm/module_map:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 4.0% Function: ~<anonymous> node:internal/fs/promises:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 4.0% Function: ~<anonymous> node:internal/blocklist:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
3 10.7% LazyCompile: ~nativeModuleRequire node:internal/bootstrap/loaders:348:29
2 66.7% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 33.3% LazyCompile: ~setupInspectorHooks node:internal/bootstrap/pre_execution:325:29
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
3 9.7% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:315:27
3 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 33.3% LazyCompile: ~table node:internal/console/constructor:482:8
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 33.3% LazyCompile: ~lazyLoadStreams node:fs:2872:25
1 100.0% LazyCompile: ~get ReadStream node:fs:3015:17
1 33.3% Function: ~<anonymous> node:tty:1:1
1 100.0% Function: ^compileForInternalLoader node:internal/bootstrap/loaders:315:27
25 14.8% /usr/lib/system/libsystem_pthread.dylib
23 92.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
4 17.4% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:394:20
4 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:495:28
4 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
4 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:70:31
3 13.0% LazyCompile: ~patchProcessObject node:internal/bootstrap/pre_execution:102:28
3 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
3 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
2 8.7% LazyCompile: ~realpathSync node:fs:2439:22
2 100.0% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:394:20
2 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:495:28
2 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
2 8.7% Function: ~<anonymous> node:internal/fs/promises:1:1
2 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
2 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
2 100.0% Function: ~<anonymous> node:internal/modules/esm/get_source:1:1
1 4.3% LazyCompile: ~setImmediate node:timers:278:22
1 100.0% LazyCompile: ~queuePending node:internal/perf/observe:104:22
1 100.0% LazyCompile: ~<anonymous> node:internal/perf/observe:298:17
1 100.0% LazyCompile: ~enqueue node:internal/perf/observe:329:17
1 4.3% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.3% LazyCompile: ~readFileSync node:fs:455:22
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1114:37
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:969:33
1 100.0% LazyCompile: ~Module._load node:internal/modules/cjs/loader:759:24
1 4.3% LazyCompile: ~queuePending node:internal/perf/observe:104:22
1 100.0% LazyCompile: ~<anonymous> node:internal/perf/observe:298:17
1 100.0% LazyCompile: ~enqueue node:internal/perf/observe:329:17
1 100.0% LazyCompile: ~measure node:internal/perf/usertiming:151:17
1 4.3% LazyCompile: ~processTicksAndRejections node:internal/process/task_queues:67:35
1 4.3% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 4.3% LazyCompile: ~next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:21:9
1 100.0% LazyCompile: ~lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 4.3% LazyCompile: ~get node:internal/console/constructor:203:14
1 100.0% LazyCompile: ~value node:internal/console/constructor:321:20
1 100.0% LazyCompile: ~log node:internal/console/constructor:359:6
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.3% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
1 100.0% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:136:19
1 100.0% LazyCompile: ~get node:internal/console/constructor:203:14
1 100.0% LazyCompile: ~value node:internal/console/constructor:321:20
1 4.3% LazyCompile: ~Socket node:net:291:16
1 100.0% LazyCompile: ~WriteStream node:tty:84:21
1 100.0% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
1 100.0% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:136:19
1 4.3% LazyCompile: ~Module._load node:internal/modules/cjs/loader:759:24
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:70:31
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 4.3% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
16 9.5% /usr/lib/system/libsystem_c.dylib
15 93.8% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 13.3% LazyCompile: ~value node:internal/console/constructor:321:20
2 100.0% LazyCompile: ~log node:internal/console/constructor:359:6
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
2 13.3% LazyCompile: ~realpathSync node:fs:2439:22
2 100.0% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:394:20
2 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:495:28
2 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
2 13.3% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
2 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 6.7% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1017:18
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1059:37
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1114:37
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:969:33
1 6.7% LazyCompile: ~syncExports node:internal/bootstrap/loaders:303:14
1 100.0% LazyCompile: ~<anonymous> node:internal/bootstrap/loaders:289:15
1 100.0% T node::loader::ModuleWrap::Evaluate(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~getESMFacade node:internal/bootstrap/loaders:280:15
1 6.7% LazyCompile: ~patchProcessObject node:internal/bootstrap/pre_execution:102:28
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 6.7% LazyCompile: ~nextTick node:internal/process/task_queues:103:18
1 100.0% LazyCompile: ~onwrite node:internal/streams/writable:426:17
1 100.0% LazyCompile: ~afterWriteDispatched node:internal/stream_base_commons:155:30
1 100.0% LazyCompile: ~writeGeneric node:internal/stream_base_commons:147:22
1 6.7% LazyCompile: ~_write node:internal/streams/writable:284:16
1 100.0% LazyCompile: ~Writable.write node:internal/streams/writable:334:36
1 100.0% LazyCompile: ~value node:internal/console/constructor:258:20
1 100.0% LazyCompile: ~log node:internal/console/constructor:359:6
1 6.7% LazyCompile: ~Module._load node:internal/modules/cjs/loader:759:24
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:70:31
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 6.7% LazyCompile: ~Duplex node:internal/streams/duplex:54:16
1 100.0% LazyCompile: ~Socket node:net:291:16
1 100.0% LazyCompile: ~WriteStream node:tty:84:21
1 100.0% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
1 6.7% LazyCompile: ~<anonymous> node:path:1082:10
1 100.0% LazyCompile: ~resolve node:path:1091:10
1 100.0% LazyCompile: ~patchProcessObject node:internal/bootstrap/pre_execution:102:28
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 6.7% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
11 6.5% T _host_request_notification
4 36.4% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 25.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~table node:internal/cli_table:55:15
1 100.0% LazyCompile: ~final node:internal/console/constructor:490:19
1 100.0% LazyCompile: ~table node:internal/console/constructor:482:8
1 25.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 25.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:70:31
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 25.0% LazyCompile: ~afterWriteTick node:internal/streams/writable:483:24
1 100.0% LazyCompile: ~processTicksAndRejections node:internal/process/task_queues:67:35
8 4.7% LazyCompile: *next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:21:9
8 100.0% LazyCompile: *lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
8 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
7 87.5% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
7 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
7 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 12.5% Function: ^test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
7 4.1% /usr/lib/libc++.1.dylib
3 42.9% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 33.3% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
1 100.0% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:136:19
1 100.0% LazyCompile: ~get node:internal/console/constructor:203:14
1 100.0% LazyCompile: ~value node:internal/console/constructor:321:20
1 33.3% LazyCompile: ~Readable node:internal/streams/readable:186:18
1 100.0% LazyCompile: ~Duplex node:internal/streams/duplex:54:16
1 100.0% LazyCompile: ~Socket node:net:291:16
1 100.0% LazyCompile: ~WriteStream node:tty:84:21
1 33.3% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
6 3.6% /usr/lib/system/libsystem_kernel.dylib
5 83.3% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 40.0% LazyCompile: ~setupWarningHandler node:internal/bootstrap/pre_execution:165:29
2 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
2 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 20.0% LazyCompile: ~nextTick node:internal/process/task_queues:103:18
1 100.0% LazyCompile: ~onwrite node:internal/streams/writable:426:17
1 100.0% LazyCompile: ~afterWriteDispatched node:internal/stream_base_commons:155:30
1 100.0% LazyCompile: ~writeGeneric node:internal/stream_base_commons:147:22
1 20.0% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 20.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
4 2.4% UNKNOWN
4 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 50.0% LazyCompile: ~value node:internal/console/constructor:321:20
2 100.0% LazyCompile: ~log node:internal/console/constructor:359:6
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 25.0% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 25.0% Function: ~<anonymous> node:internal/fs/rimraf:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 100.0% Function: ~<anonymous> node:internal/fs/promises:1:1
4 2.4% Function: ^next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:21:9
4 100.0% LazyCompile: *lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
4 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
4 100.0% Function: ^test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
4 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
4 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
4 2.4% /usr/lib/system/libsystem_platform.dylib
3 75.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 33.3% LazyCompile: ~value node:internal/console/constructor:321:20
1 100.0% LazyCompile: ~log node:internal/console/constructor:359:6
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 33.3% LazyCompile: ~openSync node:fs:581:18
1 100.0% LazyCompile: ~readFileSync node:fs:455:22
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1114:37
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:969:33
1 33.3% LazyCompile: ~lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
2 1.2% t std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> > std::__1::__pad_and_output<char, std::__1::char_traits<char> >(std::__1::ostreambuf_iterator<char, std::__1::char_traits<char> >, char const*, char const*, char const*, std::__1::ios_base&, char)
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 50.0% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:394:20
1 100.0% LazyCompile: ~Module._findPath node:internal/modules/cjs/loader:495:28
1 100.0% LazyCompile: ~resolveMainPath node:internal/modules/run_main:15:25
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:70:31
1 50.0% LazyCompile: ~setupFetch node:internal/bootstrap/pre_execution:176:20
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
2 1.2% t std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::__put_character_sequence<char, std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*, unsigned long)
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 50.0% LazyCompile: ~patchProcessObject node:internal/bootstrap/pre_execution:102:28
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 50.0% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
1 100.0% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:136:19
1 100.0% LazyCompile: ~get node:internal/console/constructor:203:14
1 100.0% LazyCompile: ~value node:internal/console/constructor:321:20
2 1.2% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% LazyCompile: ~compileFunction node:vm:308:25
2 100.0% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1017:18
2 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1059:37
2 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1114:37
2 1.2% LazyCompile: *lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:629:14
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
2 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
After:
$ node --trace-warnings --prof --no-logfile-per-isolate lib/benchmark-static-lexer.js && node --prof-process v8.log
Read 5160 bytes
┌─────────┬────────────┬───────────┬───────────┬───────────┬──────────────┐
│ (index) │ rss │ heapTotal │ heapUsed │ external │ arrayBuffers │
├─────────┼────────────┼───────────┼───────────┼───────────┼──────────────┤
│ start │ '28.13 MB' │ '6.11 MB' │ '5.46 MB' │ '0.34 MB' │ '0.04 MB' │
│ warm-up │ '36.66 MB' │ '7.61 MB' │ '5.43 MB' │ '0.32 MB' │ '0.02 MB' │
│ finish │ '36.66 MB' │ '7.61 MB' │ '5.87 MB' │ '0.32 MB' │ '0.02 MB' │
└─────────┴────────────┴───────────┴───────────┴───────────┴──────────────┘
Warm-up: 32.25229199230671ms
Test: 6.697618007659912ms
(node:76184) ExperimentalWarning: VM Modules is an experimental feature. This feature could change at any time
(Use `node --trace-warnings ...` to show where the warning was created)
Statistical profiling result from v8.log, (166 ticks, 0 unaccounted, 0 excluded).
[Shared libraries]:
ticks total nonlib name
24 14.5% /usr/lib/system/libsystem_pthread.dylib
13 7.8% /usr/lib/system/libsystem_c.dylib
9 5.4% /usr/lib/libc++.1.dylib
3 1.8% /usr/lib/system/libsystem_malloc.dylib
3 1.8% /usr/lib/system/libsystem_kernel.dylib
2 1.2% /usr/lib/system/libsystem_platform.dylib
[JavaScript]:
ticks total nonlib name
6 3.6% 5.4% LazyCompile: *next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:35:9
4 2.4% 3.6% Function: ^next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:35:9
2 1.2% 1.8% LazyCompile: *emit /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:29:9
1 0.6% 0.9% LazyCompile: *test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
[C++]:
ticks total nonlib name
46 27.7% 41.1% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
28 16.9% 25.0% T node::native_module::NativeModuleEnv::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
16 9.6% 14.3% T _host_request_notification
3 1.8% 2.7% T node::contextify::ContextifyContext::CompileFunction(v8::FunctionCallbackInfo<v8::Value> const&)
2 1.2% 1.8% t std::__1::basic_ostream<char, std::__1::char_traits<char> >& std::__1::__put_character_sequence<char, std::__1::char_traits<char> >(std::__1::basic_ostream<char, std::__1::char_traits<char> >&, char const*, unsigned long)
2 1.2% 1.8% T _shm_open
1 0.6% 0.9% t node::fs::LStat(v8::FunctionCallbackInfo<v8::Value> const&)
1 0.6% 0.9% T _mach_msg_destroy
[Summary]:
ticks total nonlib name
13 7.8% 11.6% JavaScript
99 59.6% 88.4% C++
5 3.0% 4.5% GC
54 32.5% Shared libraries
[C++ entry points]:
ticks cpp total name
118 100.0% 71.1% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
[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 1.0% are not shown.
ticks parent name
46 27.7% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
23 50.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 8.7% LazyCompile: ~WriteStream node:tty:84:21
2 100.0% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
2 100.0% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:136:19
2 100.0% LazyCompile: ~get node:internal/console/constructor:203:14
1 4.3% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% Function: ^next /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:35:9
1 100.0% LazyCompile: *lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:583:14
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.3% LazyCompile: ~wrapSafe node:internal/modules/cjs/loader:1017:18
1 100.0% LazyCompile: ~Module._compile node:internal/modules/cjs/loader:1059:37
1 100.0% LazyCompile: ~Module._extensions..js node:internal/modules/cjs/loader:1114:37
1 100.0% LazyCompile: ~Module.load node:internal/modules/cjs/loader:969:33
1 4.3% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.3% LazyCompile: ~setImmediate node:timers:278:22
1 100.0% LazyCompile: ~queuePending node:internal/perf/observe:104:22
1 100.0% LazyCompile: ~<anonymous> node:internal/perf/observe:298:17
1 100.0% LazyCompile: ~enqueue node:internal/perf/observe:329:17
1 4.3% LazyCompile: ~readFileAfterStat node:fs:331:27
1 4.3% LazyCompile: ~promisify node:internal/util:324:19
1 100.0% Function: ~<anonymous> node:internal/fs/promises:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 4.3% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 4.3% LazyCompile: ~patchProcessObject node:internal/bootstrap/pre_execution:102:28
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 4.3% LazyCompile: ~mark node:internal/perf/usertiming:94:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.3% LazyCompile: ~initializeCJSLoader node:internal/bootstrap/pre_execution:514:29
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 4.3% LazyCompile: ~getOptionValue node:internal/options:44:24
1 100.0% LazyCompile: ~setupWarningHandler node:internal/bootstrap/pre_execution:165:29
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 4.3% LazyCompile: ~getCLIOptionsFromBinding node:internal/options:18:34
1 100.0% LazyCompile: ~getOptionValue node:internal/options:44:24
1 100.0% LazyCompile: ~patchProcessObject node:internal/bootstrap/pre_execution:102:28
1 100.0% LazyCompile: ~prepareMainThreadExecution node:internal/bootstrap/pre_execution:30:36
1 4.3% LazyCompile: ~formatWithOptions node:internal/util/inspect:2024:27
1 100.0% LazyCompile: ~value node:internal/console/constructor:321:20
1 100.0% LazyCompile: ~log node:internal/console/constructor:359:6
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.3% LazyCompile: ~formatPrimitive node:internal/util/inspect:1519:25
1 100.0% LazyCompile: ~formatValue node:internal/util/inspect:745:21
1 100.0% LazyCompile: ~inspect node:internal/util/inspect:292:17
1 100.0% LazyCompile: ~_inspect node:internal/console/constructor:492:22
1 4.3% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
1 100.0% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:136:19
1 100.0% LazyCompile: ~get node:internal/console/constructor:203:14
1 100.0% LazyCompile: ~value node:internal/console/constructor:321:20
1 4.3% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 100.0% LazyCompile: ~nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 4.3% LazyCompile: ~Socket node:net:291:16
1 100.0% LazyCompile: ~WriteStream node:tty:84:21
1 100.0% LazyCompile: ~createWritableStdioStream node:internal/bootstrap/switches/is_main_thread:41:35
1 100.0% LazyCompile: ~getStdout node:internal/bootstrap/switches/is_main_thread:136:19
1 4.3% LazyCompile: ~Readable.removeListener node:internal/streams/readable:916:45
1 100.0% LazyCompile: ~value node:internal/console/constructor:258:20
1 100.0% LazyCompile: ~log node:internal/console/constructor:359:6
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.3% LazyCompile: ~Module._load node:internal/modules/cjs/loader:759:24
1 100.0% LazyCompile: ~executeUserEntryPoint node:internal/modules/run_main:70:31
1 100.0% Function: ~<anonymous> node:internal/main/run_main_module:1:1
1 4.3% LazyCompile: ~<instance_members_initializer> node:internal/perf/observe:199:1
1 100.0% LazyCompile: ~PerformanceObserver node:internal/perf/observe:205:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 4.3% Function: ^test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 4.3% LazyCompile: ~lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:583:14
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% LazyCompile: ~test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
2 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 4.3% LazyCompile: *lex /Users/wincent/code/masochist-experimental/packages/lexer/lib/lex.js:583:14
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
2 100.0% Function: ^test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
2 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
2 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 2.2% LazyCompile: ~getCLIOptionsFromBinding node:internal/options:18:34
1 100.0% Function: ^getOptionValue node:internal/options:44:24
1 100.0% Function: ~<anonymous> node:internal/modules/esm/resolve:1:1
1 100.0% LazyCompile: ~compileForInternalLoader node:internal/bootstrap/loaders:315:27
1 100.0% Function: ^nativeModuleRequire node:internal/bootstrap/loaders:348:29
1 2.2% LazyCompile: ~get node:internal/console/constructor:203:14
1 100.0% LazyCompile: ~value node:internal/console/constructor:321:20
1 100.0% LazyCompile: ~log node:internal/console/constructor:359:6
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 100.0% LazyCompile: ~<anonymous> /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:45:54
1 2.2% Function: ^test /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:32:14
1 100.0% LazyCompile: ~run /Users/wincent/code/masochist-experimental/packages/benchmark/lib/benchmark-lexer.js:39:19
1 100.0% T node::options_parser::GetCLIOptions(v8::FunctionCallbackInfo<v8::Value> const&)
1 2.2% Function: ^resolve node:path:1091:10
1 100.0% LazyCompile: ~realpathSync node:fs:2439:22
1 100.0% LazyCompile: ~toRealPath node:internal/modules/cjs/loader:394:20
1 100.0% LazyCompi…- Loading branch information
