Performance measurements for day-to-day development of Rustls

[aochagavia]

See #1205 (comment) for context

It would be very useful to have automated and accurate feedback on a PR's performance impact compared to the main branch. It should be automated, to ensure it is always used, and it should be accurate, to ensure it is actionable (i.e. too much noise would train reviewers to ignore the information). The approach used by rustc is a good example to follow, though its development required a daunting amount of work.

We might want to keep an up-to-date plot of performance over time, too, for two reasons:

1. As a coherence check (i.e. if the results are truly accurate, we should see little noise over time, and be able to explain any significant performance differences).
2. To reveal long-term performance trends after a significant series of changes (e.g. after someone spent 6 months on an effort to optimize the library, after a series of refactorings to address security audit findings, etc).

[aochagavia]

After giving it some more thought, gathering feedback, reading and experimenting, I think we probably want to go with the following approach in our initial setup:

1. Measure CPU instructions using cachegrind. It works with the default GitHub actions runners and the benchmarking code requires minimum maintenance.
2. Create additional time-based benchmarks using paired benchmarking for cases in which instruction counts alone do not suffice (e.g. when introducing more parallelism, like mentioned in this article). These benchmarks are not part of the rustls repository and the CI, because they have a higher maintenance cost, are more noisy, and are only occasionally necessary (i.e. for most PRs the instruction check should be enough).

Additional context

Measuring CPU instructions

This technique has been successfully used in tracking the Rust compiler's performance, and is generally recommended when comparing two versions of the same code to identify performance differences. It has incredibly low noise, and therefore makes for a very good metric for automatic PR checking (i.e. the automatic check will reliably identify significant performance changes).

It is not possible to deduce the exact change in runtime based on the instruction count difference (e.g. a 5% increase in instructions does not necessarily result in a 5% increase in runtime). However, if there is a significant change in instruction count, you can be fairly confident there is a significant change in runtime too. This is very useful information to have when reviewing a PR.

When more detailed information is desired, the time-based benchmarking approach described below can provide timing differences between two versions of the library.

Time-based benchmarks

Paired benchmarking is an approach to time-based benchmarks which claims to be less noisy and less computationally intensive than criterion. According to my experiments, it is able to identify performance differences with about 5µs of precision (maybe not reliably enough for a CI, but certainly reliably enough for manual use).

The basic difference between criterion and paired benchmarking is:

• Criterion tries to get an accurate measurement of a function's wall-time in isolation. It runs the function multiple times and collects the timings. You can run criterion twice, once for each version of the library, and compare the mean wall-time of both afterwards.
• Paired benchmarking assumes there is no such thing as "a function's wall-time in isolation", because of the highly fluctuating biases of modern computer systems. As an alternative, it tries to get an accurate measurement of the wall-time difference between the two versions of a function. It repeatedly runs both versions, each pair in randomized order, thereby ensuring the two runs are subject to the same system biases. Afterwards, it collects the timing differences for each pair, and obtains a highly accurate mean.

The paired benchmarking approach has a higher maintenance cost because it cannot run in isolation (i.e. cargo bench each version of the crate). It instead requires having a single benchmarking program, linked to the two versions of the library you want to compare. Here is a tentative implementation, comparing rustls 0.21.0 against 0.21.6 (you can run it with cargo run --release).

Discarded alternative

Maybe it would work to Just Use Criterion™ with a dedicated benchmarking machine, configured in a way that reduces noise (see, for instance, the configuration used for benchmarking the Rust compiler).

Would it work? This hypothesis is difficult for me to prove at the moment, because I'm working from a laptop, which according to what I've read is not ideal for low-noise benchmarks. Also, my machine doesn't seem to provide mechanisms to control things like Hyperthreading and CPU frequency scaling. In any case: without special tweaks, criterion benchmark results showed significant differences when running them multiple times for the same codebase.

Besides this, I expect that using a dedicated machine would result in additional maintenance burden and cost, which is undesirable. Having found a compelling option in instruction counts + paired benchmarking, I think we can discard this alternative.

[ctz]

definitely would be interested on the results of cpu instruction measurements on #1319 compared to main, if you're looking for a guinea pig!

[aochagavia]

@ctz thanks for the suggestion! I played with your PR and posted the results below (followed by instructions to reproduce).

Results

CPU instructions

The table below shows the diff in CPU instructions, as measured by cachegrind, using TLS13_AES_128_GCM_SHA256 with an RSA-signed certificate. "Bulk" is transferring 1MB.

	main	PR	main (sub)	PR (sub)	diff	diff (%)
new_conn_no_resume	779636	779222
handshake_no_resume	17016983	17039936	16237347	16260714	23367	0.14%
new_conn_session_id	782220	782210
handshake_session_id	17163576	17188092	16381356	16405882	24526	0.15%
new_conn_ticket	782507	782621
handshake_ticket	17159985	17186361	16377478	16403740	26262	0.16%
bulk_no_resume	30258386	30280979	13241403	13241043	-360	0.00%

Note that the CPU counts under main and PR are the numbers calculated by iai (which uses cachegrind under the hood). The CPU counts under main (sub) and PR (sub) have been tweaked by subtracting from them the counts of the setup code (i.e. the cost of creating a Connection struct, for handshakes, and the cost of the handshake, for bulk).

Paired benchmarking

Paired benchmarking showed differences of < 5 µs, which we can probably disregard as noise. As a point of reference, the non-resumed TLS handshake takes around 800 µs on my machine, and the bulk transfer (excluding handshake) around 700 µs.

Instructions to reproduce

The paired benchmarking results can be easily reproduced by cloning my experimental repository, checking out 7eb4026 and running cargo run --release.

Instruction counting requires a few more steps:

• Clone another experimental repo and check out 0b07703 .
• Run cargo bench, to get the baseline CPU counts
• Comment out the version of rustls specified in Cargo.toml, and uncomment the other version you will find there.
• Run cargo bench, to get the PR's CPU counts (iai will automatically calculate the diff for you)

Considerations

Now we need to come up with a way to interpret the results 😅 ... I'm running out of time, so I'll post some considerations later. Feel free to suggest ideas in the meantime, in case you have any!

Update: my conclusion is that, in the particular case of this PR, we can probably assume there is no meaningful performance difference. Even if the PR does make the code slower, it is by such a small margin that we cannot measure it. To illustrate the idea, imagine wall-time increases by 4x the increase in executed instructions: that means an increase of 0.6% (4 times 0.15%), which amounts to ~5 µs in the handshake scenario (0.6% of 800 µs).

[aochagavia]

Today I've been doing more testing, so here's an update with some questions.

First of all, I added TLS 1.2 benchmarks, analogous to the existing ones for TLS 1.3 (see the end of this comment for the exact details). Then, I started comparing instruction counts before and after recent PRs to get a better feeling of how the metric works in practice.

Results

• relax handling of TLS 1.3 plaintext alerts pre-encrypted data exchange: no changes.
• Split out webpki callers into separate module: no changes.
• Extract traits under crypto use (main = 22e6a87f6d5c44212f2969d1fb31ed889499b63a, pr = ae1d72f229555cbe87f7abe9784edc918750fb93): handshake instruction count increases up to 0.03% for TLS 1.2, and up to 0,14% for TLS 1.3. No wall-time increase observed using paired benchmarking (I expect it would be at most 5µs, as I mentioned at the end of my previous comment, and this is within the noise range I observe in the paired benchmarking setup).

I also compared the 0.21.0 release against current main (22e6a87f6d5c44212f2969d1fb31ed889499b63a): for TLS 1.2 there is a 0.07% instruction reduction in the handshake scenarios, and 0.05% in the data transfer scenario. For TLS 1.3 there are increases of <= 0.02%.

Conclusions

With these results I think it would be all right to wire up a CPU instruction check to CI, and to emit some kind of warning (not an error) if we observe differences above 1% in any scenario. It would still require human intervention to quantify the difference in wall-time, but that will probably be rarely required and can be manually checked using paired benchmarking (I'll make sure to write a reference implementation with clear instructions on how to use it). Does this sound like a good idea to you?

Practical details

As to the scenarios we want to consider, the current setup uses the following configurations:

• TLS 1.2 with the TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 cipher suite.
• TLS 1.3 with an RSA-signed certificate and the TLS13_AES_128_GCM_SHA256 cipher suite.

Each of these configurations has 3 handshake benchmarks (no resumption, session id resumption, ticket resumption) and one data transfer benchmark (1 MB).

Running the benchmarks is reasonably fast, so we have room to check more configurations. Drawing inspiration from the existing benchmarks, I guess we want to exercise the ECDSA code path too, and maybe also CHACHA20, by adding the following configurations:

• TLS 1.2
  • TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256
  • TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256
  • TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256
• TLS 1.3
  • TLS13_AES_128_GCM_SHA256 with an ECDSA-signed certificate.
  • TLS13_CHACHA20_POLY1305_SHA256 with an RSA-signed certificate.
  • TLS13_CHACHA20_POLY1305_SHA256 with an ECDSA-signed certificate.

It is also thinkable to introduce configurations for AES 256, SHA256 and SHA384, but my hunch is that they wouldn't add much benefits above what the ones mentioned above.

Do you have any suggestions about adding or omitting configurations in the benchmarks?

[djc]

Nice work!

Conclusions

With these results I think it would be all right to wire up a CPU instruction check to CI, and to emit some kind of warning (not an error) if we observe differences above 1% in any scenario. It would still require human intervention to quantify the difference in wall-time, but that will probably be rarely required and can be manually checked using paired benchmarking (I'll make sure to write a reference implementation with clear instructions on how to use it). Does this sound like a good idea to you?

Sounds good to me. Maybe we can tighten up the 1% a bit in order to gain experience with this? If it's just a warning in CI I think we'd rather have false positives than false negatives.

Do you have any suggestions about adding or omitting configurations in the benchmarks?

I would suggest that we limit ourselves to only one of the proposed TLS 1.2 configurations, assuming that much of the code paths in the primitives is shared between 1.2 and 1.3 anyway. Otherwise this looks good to me.

[ctz]

Does this sound like a good idea to you?

Certainly, yes.

For the "emit some kind of warning" I think https://docs.github.com/en/actions/using-workflows/workflow-commands-for-github-actions#example-of-adding-a-job-summary should fit the bill -- the CI job can just throw markdown into a file and it'll appear in the GH action job, but also echo lines of a specific format that become warnings/notices in the GH action job.

Do you have any suggestions about adding or omitting configurations in the benchmarks?

I think the ones you've listed seem like a good start.

Can we separate client and server performance footprints? I guess at the moment that is difficult because the two ends coexist in the same process, so we'd have to change that to measure them separately? (This isn't a pressing concern right now, just trying to build my understanding of what we're measuring.)

[aochagavia]

All right, I have managed to measure both sides separately (as suggested by @ctz), and have added additional test cases only for TLS 1.3 (as suggested by @djc). Below is a table showing the comparison between two commits, as an illustration. I'll be working on a PR to add a user-friendly version of this as a CI check 😉, but feel free to share any feedback you might have in the meantime.

	Main (460934b)	PR (03e8863)	Diff	Diff (%)
handshake_no_resume_1.2_rsa_aes_server	11328390	11328456	66	0.00%
handshake_no_resume_1.2_rsa_aes_client	4313610	4313721	111	0.00%
handshake_session_id_1.2_rsa_aes_server	11342659	11342590	-69	0.00%
handshake_session_id_1.2_rsa_aes_client	4326194	4326305	111	0.00%
handshake_tickets_1.2_rsa_aes_server	11346856	11347058	202	0.00%
handshake_tickets_1.2_rsa_aes_client	4329866	4330069	203	0.00%
transfer_no_resume_1.2_rsa_aes_server	8773844	8773610	-234	0.00%
transfer_no_resume_1.2_rsa_aes_client	8813879	8814185	306	0.00%
handshake_no_resume_1.3_rsa_aes_server	11518884	11518699	-185	0.00%
handshake_no_resume_1.3_rsa_aes_client	4212090	4212168	78	0.00%
handshake_session_id_1.3_rsa_aes_server	11547456	11547457	1	0.00%
handshake_session_id_1.3_rsa_aes_client	4217012	4217057	45	0.00%
handshake_tickets_1.3_rsa_aes_server	11545949	11545771	-178	0.00%
handshake_tickets_1.3_rsa_aes_client	4216910	4217068	158	0.00%
transfer_no_resume_1.3_rsa_aes_server	8784174	8784129	-45	0.00%
transfer_no_resume_1.3_rsa_aes_client	8829615	8829629	14	0.00%
handshake_no_resume_1.3_ecdsa_aes_server	1619922	1620052	130	0.01%
handshake_no_resume_1.3_ecdsa_aes_client	14015909	14016298	389	0.00%
handshake_session_id_1.3_ecdsa_aes_server	1648215	1647936	-279	-0.02%
handshake_session_id_1.3_ecdsa_aes_client	14019119	14019071	-48	0.00%
handshake_tickets_1.3_ecdsa_aes_server	1645813	1645609	-204	-0.01%
handshake_tickets_1.3_ecdsa_aes_client	14019284	14019226	-58	0.00%
transfer_no_resume_1.3_ecdsa_aes_server	8782265	8782115	-150	0.00%
transfer_no_resume_1.3_ecdsa_aes_client	8832505	8832287	-218	0.00%
handshake_no_resume_1.3_rsa_chacha_server	11528814	11528595	-219	0.00%
handshake_no_resume_1.3_rsa_chacha_client	4222069	4222173	104	0.00%
handshake_session_id_1.3_rsa_chacha_server	11558214	11558017	-197	0.00%
handshake_session_id_1.3_rsa_chacha_client	4226785	4226943	158	0.00%
handshake_tickets_1.3_rsa_chacha_server	11557596	11557487	-109	0.00%
handshake_tickets_1.3_rsa_chacha_client	4226773	4226943	170	0.00%
transfer_no_resume_1.3_rsa_chacha_server	12217524	12217509	-15	0.00%
transfer_no_resume_1.3_rsa_chacha_client	12292877	12292778	-99	0.00%
handshake_no_resume_1.3_ecdsa_chacha_server	1622553	1622394	-159	-0.01%
handshake_no_resume_1.3_ecdsa_chacha_client	14018669	14018786	117	0.00%
handshake_session_id_1.3_ecdsa_chacha_server	1651425	1651363	-62	0.00%
handshake_session_id_1.3_ecdsa_chacha_client	14021795	14021830	35	0.00%
handshake_tickets_1.3_ecdsa_chacha_server	1650116	1649961	-155	-0.01%
handshake_tickets_1.3_ecdsa_chacha_client	14021787	14021886	99	0.00%
transfer_no_resume_1.3_ecdsa_chacha_server	12216055	12215717	-338	0.00%
transfer_no_resume_1.3_ecdsa_chacha_client	12295681	12295652	-29	0.00%

[djc]

I think we should order by absolute largest diff (largest to smallest), and maybe make two separate tables where one is hidden in a <details> thing with difference, say, < 0.02?

Maybe also some aggregates? Let's say,

• client vs server,
• transfer vs handshake_no_resume vs handshake_session_id vs handshake_tickets
• ecdsa vs rsa
• aes vs chacha

Ideally there is some 4-way linear regression to see if there's statistically a difference in any of the factors.

[aochagavia]

After #1404 (PR) and later developments I think it makes sense to close this issue. I've created two follow-up issues so we can track remaining work items (#1485 and #1487).

Regarding the idea to use paired benchmarks, in the end I think the maintenance cost is just too high (hence a different approach considered in #1487).