Add profiling design doc with Perfetto + in-process sampler concept#262
Open
PhilippGrulich wants to merge 12 commits into
Open
Add profiling design doc with Perfetto + in-process sampler concept#262PhilippGrulich wants to merge 12 commits into
PhilippGrulich wants to merge 12 commits into
Conversation
Contributor
There was a problem hiding this comment.
Tracing Benchmark
Details
| Benchmark suite | Current: c71bf20 | Previous: 10a6635 | Ratio |
|---|---|---|---|
exec_mlir_add |
12.1362 ns (± 0.880853) |
10.7701 ns (± 1.25718) |
1.13 |
exec_mlir_fibonacci |
25.095 us (± 4.04228) |
13.3631 us (± 1.67729) |
1.88 |
exec_mlir_sum |
634.853 us (± 31.2305) |
513.173 us (± 15.8951) |
1.24 |
exec_cpp_add |
5.15373 ns (± 0.270737) |
4.84074 ns (± 0.975486) |
1.06 |
exec_cpp_fibonacci |
134.568 us (± 11.7118) |
97.148 us (± 14.5938) |
1.39 |
exec_cpp_sum |
25.6196 ms (± 614.354) |
35.9689 ms (± 194.582) |
0.71 |
exec_bc_add |
37.6682 ns (± 3.98057) |
43.5894 ns (± 5.2732) |
0.86 |
exec_bc_fibonacci |
540.892 us (± 7.34531) |
753.817 us (± 16.9593) |
0.72 |
exec_bc_sum |
117.982 ms (± 2.07948) |
163.437 ms (± 1.52509) |
0.72 |
exec_asmjit_add |
2.95798 ns (± 0.317144) |
3.59554 ns (± 0.522867) |
0.82 |
exec_asmjit_fibonacci |
31.0772 us (± 5.02444) |
20.7515 us (± 1.80854) |
1.50 |
exec_asmjit_sum |
6.28686 ms (± 39.9614) |
4.84254 ms (± 26.3078) |
1.30 |
exec_bc_add_noRegAlloc |
36.6334 ns (± 3.07617) |
44.3788 ns (± 6.39372) |
0.83 |
exec_bc_add_regAlloc |
36.2872 ns (± 2.71443) |
43.9551 ns (± 5.99039) |
0.83 |
exec_bc_fibonacci_noRegAlloc |
545.585 us (± 14.0333) |
751.654 us (± 14.3443) |
0.73 |
exec_bc_fibonacci_regAlloc |
542.1 us (± 7.93657) |
751.761 us (± 11.6866) |
0.72 |
exec_bc_sum_noRegAlloc |
116.72 ms (± 1.22125) |
163.167 ms (± 446.848) |
0.72 |
exec_bc_sum_regAlloc |
118.134 ms (± 2.07344) |
163.266 ms (± 1.17473) |
0.72 |
comp_mlir_add |
6.33058 ms (± 206.987) |
5.52896 ms (± 150.264) |
1.14 |
comp_mlir_ifThenElse |
7.13563 ms (± 747.075) |
6.15129 ms (± 143.859) |
1.16 |
comp_mlir_deeplyNestedIfElse |
5.71175 ms (± 166.201) |
5.04123 ms (± 67.5269) |
1.13 |
comp_mlir_loop |
7.81536 ms (± 273.735) |
7.23834 ms (± 348.192) |
1.08 |
comp_mlir_ifInsideLoop |
27.7078 ms (± 322.065) |
28.78 ms (± 822.48) |
0.96 |
comp_mlir_loopDirectCall |
11.9501 ms (± 257.488) |
12.4205 ms (± 456.737) |
0.96 |
comp_mlir_pointerLoop |
26.7967 ms (± 272.682) |
28.18 ms (± 795.83) |
0.95 |
comp_mlir_staticLoop |
5.69151 ms (± 662.571) |
4.98862 ms (± 45.2884) |
1.14 |
comp_mlir_fibonacci |
10.748 ms (± 202.449) |
10.5174 ms (± 254.747) |
1.02 |
comp_mlir_gcd |
9.62961 ms (± 208.259) |
9.43739 ms (± 66.7206) |
1.02 |
comp_mlir_nestedIf10 |
10.8377 ms (± 332.976) |
10.9118 ms (± 562.598) |
0.99 |
comp_mlir_nestedIf100 |
25.604 ms (± 727.384) |
25.5045 ms (± 614.911) |
1.00 |
comp_mlir_chainedIf10 |
11.3477 ms (± 251.524) |
9.77351 ms (± 299.372) |
1.16 |
comp_mlir_chainedIf100 |
59.8369 ms (± 1.24551) |
20.2026 ms (± 289.302) |
2.96 |
comp_cpp_add |
22.1998 ms (± 890.541) |
25.3523 ms (± 536.121) |
0.88 |
comp_cpp_ifThenElse |
23.9098 ms (± 1.26905) |
25.6938 ms (± 472.16) |
0.93 |
comp_cpp_deeplyNestedIfElse |
25.4076 ms (± 1.99446) |
26.2772 ms (± 280.811) |
0.97 |
comp_cpp_loop |
24.0882 ms (± 1.21658) |
25.3249 ms (± 302.8) |
0.95 |
comp_cpp_ifInsideLoop |
24.1144 ms (± 1.04087) |
26.0316 ms (± 253.783) |
0.93 |
comp_cpp_loopDirectCall |
23.4103 ms (± 498.243) |
25.5171 ms (± 227.43) |
0.92 |
comp_cpp_pointerLoop |
23.9918 ms (± 1.70698) |
25.7051 ms (± 267.651) |
0.93 |
comp_cpp_staticLoop |
22.4187 ms (± 565.739) |
25.1416 ms (± 369.29) |
0.89 |
comp_cpp_fibonacci |
23.3358 ms (± 1.39266) |
25.9456 ms (± 429.397) |
0.90 |
comp_cpp_gcd |
22.3534 ms (± 385.038) |
25.3955 ms (± 444.048) |
0.88 |
comp_cpp_nestedIf10 |
25.972 ms (± 1.4389) |
28.4827 ms (± 851.989) |
0.91 |
comp_cpp_nestedIf100 |
57.9219 ms (± 865.457) |
62.4417 ms (± 958.238) |
0.93 |
comp_cpp_chainedIf10 |
29.0237 ms (± 1.39339) |
31.448 ms (± 927.552) |
0.92 |
comp_cpp_chainedIf100 |
90.1766 ms (± 2.99112) |
92.2053 ms (± 608.636) |
0.98 |
comp_bc_add |
10.6292 us (± 2.52224) |
14.582 us (± 1.75527) |
0.73 |
comp_bc_ifThenElse |
13.316 us (± 2.7087) |
18.6811 us (± 3.58857) |
0.71 |
comp_bc_deeplyNestedIfElse |
18.0823 us (± 2.5519) |
22.7163 us (± 4.31134) |
0.80 |
comp_bc_loop |
13.971 us (± 2.56411) |
18.9731 us (± 4.056) |
0.74 |
comp_bc_ifInsideLoop |
15.6371 us (± 2.8635) |
21.2198 us (± 3.74251) |
0.74 |
comp_bc_loopDirectCall |
14.609 us (± 2.51895) |
18.9753 us (± 3.3135) |
0.77 |
comp_bc_pointerLoop |
14.3163 us (± 2.45465) |
20.1783 us (± 3.72759) |
0.71 |
comp_bc_staticLoop |
12.5108 us (± 2.84335) |
17.3933 us (± 3.71277) |
0.72 |
comp_bc_fibonacci |
14.5886 us (± 3.2537) |
18.4986 us (± 2.35865) |
0.79 |
comp_bc_gcd |
13.0278 us (± 2.41125) |
17.9795 us (± 2.53701) |
0.72 |
comp_bc_nestedIf10 |
31.8209 us (± 4.64693) |
34.8719 us (± 4.27966) |
0.91 |
comp_bc_nestedIf100 |
191.633 us (± 10.1774) |
191.397 us (± 12.8541) |
1.00 |
comp_bc_chainedIf10 |
40.0329 us (± 6.13685) |
49.1121 us (± 5.49462) |
0.82 |
comp_bc_chainedIf100 |
300.804 us (± 7.76016) |
297.447 us (± 12.8065) |
1.01 |
comp_asmjit_add |
15.8212 us (± 3.9226) |
20.7886 us (± 3.14001) |
0.76 |
comp_asmjit_ifThenElse |
27.7089 us (± 6.95762) |
32.8265 us (± 5.22408) |
0.84 |
comp_asmjit_deeplyNestedIfElse |
41.8998 us (± 6.5984) |
56.0766 us (± 9.15709) |
0.75 |
comp_asmjit_loop |
28.229 us (± 7.02468) |
35.0292 us (± 5.17887) |
0.81 |
comp_asmjit_ifInsideLoop |
42.4154 us (± 9.33085) |
57.2267 us (± 11.6151) |
0.74 |
comp_asmjit_loopDirectCall |
31.0005 us (± 6.914) |
44.056 us (± 5.42689) |
0.70 |
comp_asmjit_pointerLoop |
35.0896 us (± 7.08235) |
48.1419 us (± 8.30256) |
0.73 |
comp_asmjit_staticLoop |
22.4002 us (± 5.97363) |
28.3138 us (± 5.3941) |
0.79 |
comp_asmjit_fibonacci |
30.626 us (± 6.78545) |
43.0434 us (± 8.60098) |
0.71 |
comp_asmjit_gcd |
27.7098 us (± 6.92405) |
35.0731 us (± 6.56689) |
0.79 |
comp_asmjit_nestedIf10 |
85.1294 us (± 8.34141) |
104.565 us (± 14.2612) |
0.81 |
comp_asmjit_nestedIf100 |
1013.4700000000001 us (± 73040) |
1068.05 us (± 146903) |
0.95 |
comp_asmjit_chainedIf10 |
132.399 us (± 12.9501) |
154.231 us (± 15.4403) |
0.86 |
comp_asmjit_chainedIf100 |
2.07341 ms (± 83.1943) |
2.13529 ms (± 28.6135) |
0.97 |
e2e_tiered_bc_to_mlir |
38.7813 us (± 10.6065) |
56.5271 us (± 14.5799) |
0.69 |
e2e_single_mlir |
6.01187 ms (± 190.473) |
5.53847 ms (± 193.361) |
1.09 |
ssa_add |
192.293 ns (± 19.4588) |
204.202 ns (± 28.1667) |
0.94 |
ssa_ifThenElse |
448.308 ns (± 35.3891) |
484.779 ns (± 51.85) |
0.92 |
ssa_deeplyNestedIfElse |
1.30985 us (± 77.9136) |
1.20907 us (± 105.009) |
1.08 |
ssa_loop |
488.379 ns (± 33.1392) |
533.363 ns (± 80.3068) |
0.92 |
ssa_ifInsideLoop |
1022.4599999999999 ns (± 52863.700000000004) |
959.38 ns (± 91.9966) |
1.07 |
ssa_loopDirectCall |
487.77 ns (± 34.6548) |
538.332 ns (± 83.9372) |
0.91 |
ssa_pointerLoop |
589.727 ns (± 49.3279) |
612.761 ns (± 60.7414) |
0.96 |
ssa_staticLoop |
436.933 ns (± 24.0491) |
475.509 ns (± 52.7257) |
0.92 |
ssa_fibonacci |
505.449 ns (± 44.5115) |
530.832 ns (± 47.7214) |
0.95 |
ssa_gcd |
453.78 ns (± 38.5603) |
468.824 ns (± 43.3429) |
0.97 |
tiered_compile_addOne |
39.0009 us (± 12.5568) |
55.7034 us (± 13.3607) |
0.70 |
single_compile_mlir_addOne |
3.54143 ms (± 100.202) |
3.28567 ms (± 103.998) |
1.08 |
single_compile_cpp_addOne |
21.6974 ms (± 725.536) |
25.0471 ms (± 510.067) |
0.87 |
single_compile_bc_addOne |
41.0337 us (± 9.9618) |
56.0618 us (± 12.9099) |
0.73 |
tiered_compile_sumLoop |
58.5078 us (± 11.7632) |
77.4694 us (± 16.0654) |
0.76 |
single_compile_mlir_sumLoop |
5.41473 ms (± 133.264) |
5.30892 ms (± 116.288) |
1.02 |
single_compile_cpp_sumLoop |
22.0676 ms (± 613.545) |
25.7075 ms (± 518.009) |
0.86 |
single_compile_bc_sumLoop |
60.473 us (± 11.3704) |
77.1814 us (± 14.9321) |
0.78 |
exec_bc_addOne |
31.9441 ns (± 4.48747) |
37.3468 ns (± 8.00576) |
0.86 |
exec_mlir_addOne |
357.921 ns (± 6.54798) |
258.029 ns (± 4.30464) |
1.39 |
exec_cpp_addOne |
3.62053 ns (± 0.381176) |
3.6505 ns (± 0.452295) |
0.99 |
exec_interpreted_addOne |
35.5153 ns (± 1.72613) |
38.3209 ns (± 4.07534) |
0.93 |
trace_add |
2.64982 us (± 189.556) |
2.49638 us (± 295.356) |
1.06 |
completing_trace_add |
2.66462 us (± 208.607) |
2.4736 us (± 334.61) |
1.08 |
trace_ifThenElse |
9.15787 us (± 1.14652) |
9.30328 us (± 1.67908) |
0.98 |
completing_trace_ifThenElse |
5.22623 us (± 621.734) |
4.70958 us (± 574.319) |
1.11 |
trace_deeplyNestedIfElse |
26.3307 us (± 3.91838) |
26.0099 us (± 3.07346) |
1.01 |
completing_trace_deeplyNestedIfElse |
14.1943 us (± 2.10736) |
13.1091 us (± 1.70257) |
1.08 |
trace_loop |
9.14376 us (± 868.375) |
8.71348 us (± 1.22788) |
1.05 |
completing_trace_loop |
5.35013 us (± 661.606) |
4.77327 us (± 516.624) |
1.12 |
trace_ifInsideLoop |
17.1384 us (± 1.3999) |
17.3334 us (± 2.90873) |
0.99 |
completing_trace_ifInsideLoop |
9.64352 us (± 1.19091) |
8.82408 us (± 1.28846) |
1.09 |
trace_loopDirectCall |
9.31741 us (± 1.85661) |
8.96005 us (± 1.49533) |
1.04 |
completing_trace_loopDirectCall |
5.46257 us (± 657.436) |
5.1524 us (± 762.558) |
1.06 |
trace_pointerLoop |
15.1053 us (± 2.65061) |
14.2471 us (± 2.16149) |
1.06 |
completing_trace_pointerLoop |
11.3219 us (± 835.324) |
10.4746 us (± 1.84546) |
1.08 |
trace_staticLoop |
7.7574 us (± 660.509) |
7.6142 us (± 1.0114) |
1.02 |
completing_trace_staticLoop |
7.71066 us (± 690.874) |
7.46691 us (± 872.687) |
1.03 |
trace_fibonacci |
10.5784 us (± 1.68458) |
10.1531 us (± 1.57566) |
1.04 |
completing_trace_fibonacci |
6.97325 us (± 888.192) |
6.17947 us (± 858.737) |
1.13 |
trace_gcd |
8.29959 us (± 1.07316) |
8.05058 us (± 1.02295) |
1.03 |
completing_trace_gcd |
4.41986 us (± 546.563) |
4.06246 us (± 448.501) |
1.09 |
trace_nestedIf10 |
40.432 us (± 5.05762) |
37.7878 us (± 6.23274) |
1.07 |
completing_trace_nestedIf10 |
40.1531 us (± 2.49769) |
38.9354 us (± 7.34432) |
1.03 |
trace_nestedIf100 |
1.32836 ms (± 24.9944) |
1.34644 ms (± 53.7282) |
0.99 |
completing_trace_nestedIf100 |
1.36837 ms (± 29.4183) |
1.35177 ms (± 56.6128) |
1.01 |
trace_chainedIf10 |
97.7387 us (± 9.44156) |
99.7738 us (± 12.6143) |
0.98 |
completing_trace_chainedIf10 |
52.6085 us (± 5.93921) |
49.9159 us (± 9.0803) |
1.05 |
trace_chainedIf100 |
4.03363 ms (± 32.1364) |
4.48434 ms (± 79.2886) |
0.90 |
completing_trace_chainedIf100 |
2.41413 ms (± 26.9823) |
2.26925 ms (± 73.0211) |
1.06 |
ir_add |
825.927 ns (± 70.1951) |
772.195 ns (± 71.3318) |
1.07 |
ir_ifThenElse |
1.67877 us (± 126.72) |
1.61196 us (± 182.266) |
1.04 |
ir_deeplyNestedIfElse |
3.69999 us (± 151.074) |
3.38468 us (± 292.836) |
1.09 |
ir_loop |
1.74178 us (± 126.91) |
1.65684 us (± 243.329) |
1.05 |
ir_ifInsideLoop |
3.20344 us (± 574.739) |
2.89326 us (± 320.554) |
1.11 |
ir_loopDirectCall |
1.99926 us (± 122.463) |
1.81889 us (± 168.556) |
1.10 |
ir_pointerLoop |
2.13117 us (± 129.631) |
2.05088 us (± 272.65) |
1.04 |
ir_staticLoop |
1.56701 us (± 124.131) |
1.51351 us (± 200.357) |
1.04 |
ir_fibonacci |
1.83904 us (± 101.487) |
1.77363 us (± 155.603) |
1.04 |
ir_gcd |
1.59182 us (± 94.4897) |
1.56065 us (± 170.558) |
1.02 |
ir_nestedIf10 |
8.69538 us (± 383.046) |
8.02456 us (± 1.15304) |
1.08 |
ir_nestedIf100 |
92.569 us (± 2.84265) |
87.6189 us (± 6.58879) |
1.06 |
ir_chainedIf10 |
13.363 us (± 847.924) |
11.6437 us (± 1.02792) |
1.15 |
ir_chainedIf100 |
168.251 us (± 3.72215) |
164.697 us (± 8.40094) |
1.02 |
This comment was automatically generated by workflow using github-action-benchmark.
c5c41d1 to
dd5f46b
Compare
Implements step 1 of the profiling rollout described in docs/profiling.md: a new plugins/profile/ library exposing Profiler::startRegion/endRegion/ ScopedRegion/traceCounter as inline wrappers around three C-ABI runtime entry points. The stub runtime logs via nautilus::log and records events in a process-global buffer exposed through a Recorder header for tests. Profiler calls lower through the existing ProxyCallOperation path with ModRef + willReturn + noUnwind attributes set, so no backend-specific work is required. BasicRegionTest drives startRegion/endRegion, ScopedRegion, and traceCounter across interpreter, MLIR, CPP, and BC backends via forEachBackend. AsmJIT is excluded per decision D1 in the design doc. Plugin is gated on ENABLE_PROFILE_PLUGIN (default OFF).
…p, sampler
Builds out steps 3–6 of the rollout described in docs/profiling.md:
- TraceWriter.hpp + flushTrace() writes Chrome Trace Event JSON that loads
natively in ui.perfetto.dev. openModule/closeModule group regions onto
per-thread virtual tracks with metadata "thread_name" entries.
- Event struct now carries timestamp_us / tid / module / stack so the
recorder is a structured source for all downstream sinks.
- Instrument.hpp: profile::instrument("name", fn) returns a wrapped
callable suitable for registerFunction, turning a traced function into
a region-bracketed one with no body edits.
- JitSymbols.hpp/.cpp: lock-free JIT symbol registry with atomic snapshot
publishing and binary-search lookup. writePerfMap() emits the standard
/tmp/perf-<pid>.map format for external perf tools.
- New jitCompiledFunctionObserver hook in LLVMBackendHooks is invoked
from MLIRExecutable::getInvocableFunctionPtr; MLIRProfilePluginInit
wires it to registerJitCode under a static initializer, with
ensureMLIRBackendHookInstalled() available to force linking from a
static-archive configuration.
- Sampler.{hpp,cpp}: SIGPROF-based in-process sampler. Dedicated sampler
thread pthread_kills registered targets on a timer; the signal handler
walks the stack with backtrace() into a per-thread SPSC ring; consumer
resolves frames via lookupJitSymbol + dladdr + abi demangle and emits
Event::Kind::Sample entries alongside regions. No reliance on
/proc or ITIMER — works identically on Linux and macOS.
BasicRegionTest grows to 10 cases covering flushTrace output, openModule
grouping, instrument() wrapping, JIT symbol lookups, the MLIR observer
hook, and end-to-end SIGPROF capture.
…-to-end
Standalone executable under plugins/profile/test/ that exercises every
piece of the profile plugin together:
- Outer Nautilus function `pipeline` bracketed by pipeline.total and
pipeline.iter regions with a pipeline.i counter per iteration.
- Two inner Nautilus functions `hashStep` / `crunchStep`, each with its
own ScopedRegion, called from the outer function (they inline into
the trace so their regions nest under the caller).
- Native C++ function `nativeMix` reached via invoke() inside
crunchStep. Marked extern "C" + visibility("default") and linked
with ENABLE_EXPORTS so the sampler's dladdr can name it.
- MLIR backend with ensureMLIRBackendHookInstalled() so JIT'd code
shows up as execute[mlir] in sampler stacks.
- Per-module track via openModule("nested_demo") wrapping the measured
run; the warm-up call goes to the default track.
- SIGPROF sampler at 2 kHz, registered on the main thread.
- flushTrace writes /tmp/nautilus-nested-profile.json for ui.perfetto.dev.
A 50-iteration, 2000-inner-loop run produces ~500k region/counter events
and 4096 sampled stacks. The sampled stacks include frames named
nativeMix, execute[mlir], __nautilus_profile_begin/end, sigprof_handler,
and the full ModuleFunction/CompiledFunction dispatch chain, proving
native+JIT symbolication works end-to-end.
Not a Catch2 test — run manually:
./build/plugins/profile/test/demo_nested_profile
MLIRProfilePluginInit now infers function sizes instead of hard-coding a
4 MB default:
1) Multiple functions from the same compilation: size is the gap to
the next address-sorted neighbor that lives in the same OS
executable region. Recomputed for every earlier entry on each new
registration.
2) Last / only function: query the OS virtual-memory map for the
region containing the address. Linux uses /proc/self/maps; macOS
uses mach_vm_region. The region's remaining bytes after the
address bound the function's code.
3) Fallback (4 MB) retained for the rare case where neither bound
can be determined.
On the existing demo this collapses execute[mlir] from a 4 MB range
down to 0x1000 (the actual JIT mmap size), so samples landing just
outside the JIT region no longer get mis-attributed to it.
The bulky runtime-demo moves from plugins/profile/test/DemoNestedProfile.cpp
to example/src/DemoProfile.cpp, joining the other demo executables at
the canonical location. The example CMakeLists forces ENABLE_PROFILE_PLUGIN
and wires demo_profile with --whole-archive + ENABLE_EXPORTS so the
profile plugin's static-initializer TU is kept and -rdynamic lets the
sampler's dladdr name local symbols.
Run with: cmake -S example -B example/build && cmake --build example/build --target demo_profile && ./example/build/demo_profile
Samples were stamped with steady_clock::time_since_epoch while regions were stamped with (now - session_start), putting them on incompatible timelines. Any post-hoc correlation of a sample to the region that was open at its capture moment failed trivially because the two timestamp spaces never overlapped. profile_runtime.cpp exposes sessionNowMicros() for the sampler to call from its signal handler. The handler's hot path remains a relaxed atomic load plus one steady_clock::now(), matching the recorder's own timing path. All 10 plugin tests still pass; the demo now produces a unified flamegraph where each sample sits under the region chain that was live when it fired.
At 256 iterations the native function ran fast enough (~100 ns at -O3) that the sampler almost never caught it on the stack — 0/4096 samples in the example build — and the unified flamegraph's answer to 'does the invoke() target appear?' was a misleading no. With 4096 iterations the function dominates the per-call cost and 732/4096 (17.9 %) samples now land in nativeMix, placing it correctly under the crunch_step region in the flamegraph.
Main's f1b569a introduced a nautilus::compiler::mlir::MLIRJit wrapper around mlir::ExecutionEngine with Options::eventListeners exposing the underlying ORC object-linking layer's listener slot, plus a matching engine::Options::addMLIRJitEventListener field. That's the clean API we wanted for Task 2: authoritative per-function (addr, size) instead of /proc/self/maps heuristics. Migration: * Delete plugins/profile/src/MLIRProfilePluginInit.cpp and remove jitCompiledFunctionObserver + ensureMLIRBackendHookInstalled. The observer hook in MLIRExecutable::getInvocableFunctionPtr is gone. * New plugins/profile/src/MLIRJitEventListener.cpp subclasses llvm::JITEventListener. notifyObjectLoaded iterates the emitted ObjectFile's symbols via llvm::object::computeSymbolSizes, filters to ST_Function, and maps each symbol's section-relative value to a runtime address via LoadedObjectInfo::getSectionLoadAddress. Registered via a Meyers-singleton getter profile::mlirJitEventListener(). * Compiled -fno-rtti because the subclass's vtable would otherwise reference typeinfo symbols LLVM's libs don't export. Same rationale as MLIRJitEventListenerTestFixture.cpp upstream. * Demo and test wire the listener in via options.addMLIRJitEventListener(profile::mlirJitEventListener()). No more static-initializer or whole-archive dance. Result: the demo's perf map now lists four real symbols with their object-file sizes (execute=406 B, the three wrappers 19-35 B) instead of one umbrella entry at the VM-region granularity. Sampled stacks continue to resolve execute[mlir] and also nativeMix at the expected frequencies (4096/4096 and 777/4096 respectively).
Replaces the vDSO clock_gettime call on the profiler's hot path with a
raw cycle-counter read. Two coordinated changes:
Level A — TSC-backed timebase in the runtime:
* detail::calibrateTimebase() runs once on first use. On x86 it checks
CPUID.80000007H:EDX[8] for invariant TSC; arm64 always uses CNTVCT.
Where neither is available, falls back to steady_clock::now() in
nanoseconds with a 1000 ticks/µs divisor.
* Event::timestamp_us is renamed to timestamp_ticks and stores the raw
cycle counter. Conversion to microseconds is deferred to flushTrace
so the hot path never divides.
* sessionNowTicks() replaces sessionNowMicros(); the SIGPROF sampler
consumes the same counter so region/sample correlation keeps the same
monotonic timeline.
* clearRecordedEvents() resets only the baseline, not the calibration —
subsequent sessions still benefit from the one-time calibrate cost.
MLIR intrinsic — inline the counter read inside JIT'd code:
* New C-ABI entry points __nautilus_profile_{begin,end,counter_i64}_ticks
accept a pre-measured tick value and skip the clock read entirely.
* plugins/profile/src/MLIRProfileIntrinsics.cpp subclasses
MLIRIntrinsicPlugin. For each of the three default entry points, the
lowering emits:
%t = llvm.call_intrinsic "llvm.readcyclecounter"() : () -> i64
%fn = llvm.inttoptr <address of _ticks entry> : i64 -> !llvm.ptr
llvm.call %fn(%name, [%value,] %t) : ...
The callee address is baked into the JIT IR as a constant, so the
emitted machine code is one rdtsc + one direct call.
* registerMLIRIntrinsics() adds the plugin to the global
MLIRIntrinsicPluginRegistry behind a std::once_flag. Called
automatically the first time mlirJitEventListener() is invoked, so
users who add the listener via Options::addMLIRJitEventListener get
the inlined counter for free.
Effect on demo_profile:
Before the change, 60 % of sampled stacks sat in
__nautilus_profile_begin/end/counter_i64 → syscall (clock_gettime).
After, clock_gettime disappears from every stack and the _ticks
variants appear instead. Resolvable native work (nativeMix) gains
share from 19 % to 23 % of samples; the remaining syscall time is
operator-delete in the recorder's Event push path (allocator
overhead, not clock overhead) — that's Level C territory
(per-thread lock-free ring with interned names), a separate change.
Replaces the single mutex-protected std::vector<Event> region store with
a per-thread SPSC ring of trivially-copyable RegionEvents. Each event
stored on the hot path is 40 bytes (ticks + name_ptr + module_ptr + value
+ kind); names and module labels are stored as raw const char* pointers
under the existing contract that Profiler::startRegion arguments have
static storage.
Drain time (flushTrace / takeRecordedEvents / clearRecordedEvents) walks
every registered ring, SPSC-drains into a std::vector<Event>, materializes
the std::strings there, and merge-sorts by timestamp. All allocator
traffic for region events is now at flush time only — once per trace
export, not once per event.
Sample events keep the existing global mutex-protected buffer (they are
~2 kHz and already land on the consumer thread, so there's nothing to
gain from making them lock-free too).
Demo impact (same workload, same hardware):
post-TSC-only post-Level-C
samples in nativeMix 22.8 % 99.5 %
samples in syscall 76.0 % 0.0 %
samples in _ticks variants 19 % combined 0.1 % combined
The profiler's observer effect on the measured workload dropped from
~77 % to ~0.5 %. The 99.5 % nativeMix attribution matches the ground
truth of what the pipeline is doing: four calls per iteration into a
4096-iter splittable-random mix.
Public API (Recorder::Event with std::string name/module) is unchanged.
The Kind enum and its values are unchanged. No test modifications
needed; all 10 profile-plugin tests continue to pass.
286b358 to
dc93c8d
Compare
…ring
The previous Chrome Trace JSON output rendered regions as nested duration
slices on a Perfetto timeline (which works well) but emitted samples as
ph:"i" instant markers — Perfetto's UI doesn't aggregate those into a
flamegraph and inline-stored stacks bloated the file.
This commit adds a hand-rolled Perfetto trace writer that produces the
native Trace protobuf, with no dependency on the Perfetto SDK or protoc:
* plugins/profile/src/PerfettoTraceWriter.{hpp,cpp}: ~150 LOC of
protobuf wire-format primitives (varint, string, embedded message,
packed varint repeated) plus the field-ID constants for every
proto used (TracePacket, TrackDescriptor, ProcessDescriptor,
ThreadDescriptor, TrackEvent, InternedData, InternedString, Frame,
Callstack, Mapping, PerfSample). Field numbers cross-checked
against upstream perfetto.protos.
* Each (tid, module) pair becomes one ThreadDescriptor track and one
child counter track. Regions become TrackEvent SLICE_BEGIN/END;
counters become TrackEvent COUNTER. Samples become PerfSample
packets that reference an interned Callstack iid.
* Sampled stacks share one InternedData packet at the start of the
sequence: every unique frame name → InternedString, every unique
frame → Frame, every unique callstack → Callstack. Subsequent
PerfSample packets carry NEEDS_INCREMENTAL_STATE so the UI uses
the interned tables.
* Timestamps are converted from raw cycle-counter ticks to nanoseconds
using the session's calibrated ticks_per_us, with clock_id =
BUILTIN_CLOCK_MONOTONIC.
Public API: new flushPerfettoTrace(path) in TraceWriter.hpp. The
existing flushTrace (Chrome JSON) is retained for tools that prefer it
or for debugging the recorder itself.
The demo now writes /tmp/nautilus-nested-profile.perfetto-trace as the
recommended output. The trace from the same workload that previously
took 60 MB as Chrome JSON drops to 626 KiB (~96x smaller) — the
interning of frame names, frames, and callstacks does most of the work,
and the binary protobuf encoding does the rest.
A new "flushPerfettoTrace writes a binary protobuf trace" test verifies
the file is non-empty, starts with the correct top-level Trace.packet
tag (0x0a), and contains the user-supplied region names embedded as
length-delimited bytes fields. 11/11 plugin tests pass.
…protobuf
flushPerfettoTrace was the recommended path since it gives the Perfetto UI
proper CPU-sampling flamegraphs and per-(thread, module) counter tracks
instead of orphan ph:i markers and overlaid counter values. Now that the
binary path is the only one we want to support, fold it into flushTrace
and delete the JSON path entirely:
* TraceWriter.hpp: removed flushPerfettoTrace; flushTrace now writes
Perfetto protobuf via the existing PerfettoTraceWriter.
* profile_runtime.cpp: removed the appendEscaped helper, the
VirtualTidTable class, the entire JSON serializer (~110 lines),
and the now-unused <fstream>/<cstdio>/<unordered_map> includes.
* BasicRegionTest.cpp: dropped the "Chrome trace JSON" test; the
Perfetto test renames to "Profile plugin: flushTrace writes a
Perfetto protobuf trace".
* DemoProfile.cpp: header comment + flushTrace call updated.
Tests: 10/10 plugin tests pass. Demo writes a 626 KiB
.perfetto-trace as before.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
No description provided.