Created Measuring performance (markdown)

Sam McCall 2021-03-11 00:11:48 +01:00
parent 505506491f
commit e0e2202ba2

54
Measuring-performance.md Normal file

@ -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.