diff --git a/Measuring-performance.md b/Measuring-performance.md new file mode 100644 index 0000000..0cbe250 --- /dev/null +++ b/Measuring-performance.md @@ -0,0 +1,54 @@ +It can be useful to know the performance impact of a code change in a real-world scenario (e.g. large codebase). + +The best way to do this is to record a fixed clangd session that you can replay, and extract timings from the event logs. Then you can run it against the old/new code, run it repeatedly to reduce noise etc. + +## Useful flags + + - `--input-mirror-file=/tmp/mirror` will record editor->server messages, which can later be fed back into clangd. (Short sessions work best). + - `--input-style=delimited` makes it easier to edit these editor->server messages by hand + - injecting a `sync` message will force clangd to wait for everything (e.g. indexing) to finish before continuing + - running with env `CLANGD_TRACE=/tmp/trace.json` will emit machine-readable timings of various events annotated with `trace::Span` + - Flags like `-sync -background-index=0 -enable-config=0` improve determinism/isolation a bit + +## Example: measuring dynamic preamble indexing + +This is easy to trigger: we just need to open a file and wait for it to get indexed. The indexing happens during the "Running PreambleCallback" event which we want the duration of. + +First we create a basic clangd session script: +``` +env CLANGD_FLAGS=-input-mirror-file=/tmp/mirror vim clang-tools-extra/clangd/XRefs.cpp +``` +After opening and then closing vim, we look at the /tmp/mirror file, and convert it to delimited format (Replace the `Content-Length: NNN\n` at end of lines with `\n---\n`. + +If we replay it into clangd immediately we see from the logs that it exits too quickly, before actually indexing. So we add the `sync` message `{"jsonrpc":"2.0","id":999,"method":"sync","params":null}` at the end. + +Now we can replay this and produce a trace: +``` +env CLANGD_TRACE=/tmp/trace.json bin/clangd -sync --background-index=0 -pretty -input-style=delimited --enable-config=0 < /tmp/mirror +``` + +Looking at the trace file we can see the event we want: +``` + { + "pid": 0, + "ph": "X", + "name": "Running PreambleCallbacks", + "ts": 4283638.0920000002, + "tid": 485893, + "dur": 1216083.5929999994, + "args": {} + }, +``` + +We can extract this with `jq`, also grabbing another event for reference: +``` +jq -c '.traceEvents[] | select(IN(.name; "BuildPreamble", "Running PreambleCallback")) | {(.name): .dur}' < /tmp/trace.json +``` + +This produces the output we want: +``` +{"Running PreambleCallback":1216083.5929999994} +{"BuildPreamble":5523891.464} +``` + +Wrapping the last two steps in a script and running this several times on both the old & new code produces useful benchmark numbers. \ No newline at end of file