Increase runtime of performance tests to O(10 ms) to increase SNR #2063
Conversation
simonjbeaumont
force-pushed
the
run-longer-benchmarks-to-increase-snr
branch
2 times, most recently
from
1260844
to
a75b7c9
Compare
Lukasa
added
the
needs-no-version-bump
|
@swift-nio-bot test perf please |
|
!!! Couldn't read commit file !!! |
|
Huh, I wonder if we overshot: the build timed out after 10 minutes. |
|
Ah, I see why: the output numbers in the chart aren't ns, they're fractional seconds. These scaling factors are all about 10^9 too high. |
🤦 Should have traced my way through to the outputs, I just read this which deals in nanoseconds. |
simonjbeaumont
force-pushed
the
run-longer-benchmarks-to-increase-snr
branch
from
a75b7c9
to
9d3eb26
Compare
|
@swift-nio-bot test perf please |
|
!!! Couldn't read commit file !!! |
|
@Lukasa I have reworked the script to work out a scaling factor with appropriate units now and updated the PR description with its output. I've also adjusted all the iterations to be in line with what we're looking for: a O(100 ms) hot loop.
Well FWICT each test is run 10 times and an average is taken: There are 62 tests, each of which taking O(100 ms), so upper bounded by 1 second. That means we could slightly overshoot 10 mins in the worst case just with the hot loops. We'd need some headroom to allow for warmups and compile time. The current run got this far... ...which was test 44/62. Looking at the output, it seems that we have managed to get O(100 ms) for all the bodies though, so if we want this, I guess we should increase the CI timeout? |
|
Hmm, does that math check out? If each test run is ~100ms, then 10 test runs is 1 second, and 62 tests adds up to 62 seconds, a.k.a 1 minute. That shouldn't be a problem, should it? |
|
Ah, but many of these are closer to 1s per run. Can we drop an order of magnitude off them all, so none of them go above 100ms? That should make this fly by. |
The maths checks out with O(100ms) rather than ~100ms. There's an order of magnitude gap in the worst case. I was thinking we were aiming for "hundreds of ms".
OK... do you want to include reducing existing ones that currently take many hundreds of ms? E.g. the locking ones? If so, I can rinse and repeat this exercise to shoot for "tens of ms". |
|
Yeah, I think we should probably shoot for tens of ms. |
simonjbeaumont
force-pushed
the
run-longer-benchmarks-to-increase-snr
branch
from
9d3eb26
to
079cc84
Compare
|
@swift-nio-bot test perf please |
|
!!! Couldn't read commit file !!! |
|
@swift-nio-bot test perf please |
simonjbeaumont
changed the title
|
!!! Couldn't read commit file !!! |
@Lukasa what's the story here? I thought maybe this was because it was out of date with |
|
The run seems to have silently failed. Let's ask it again, but if it happens again we'll need to investigate why the perf runner failed to complete. |
|
@swift-nio-bot test perf please |
|
!!! Couldn't read commit file !!! |
|
Yeah that implies an issue. I'll try to reproduce it. |
|
Hmm, I don't reproduce this locally running the perf tests on 5.6. I'll try 5.4 when I start my work day and move to my Intel machine. |
|
@swift-nio-bot test perf please |
|
!!! Couldn't read commit file !!! |
|
@swift-nio-bot test perf please |
|
!!! Couldn't read commit file !!! |
|
@swift-nio-bot test perf please |
|
!!! Couldn't read commit file !!! |
|
@swift-nio-bot test perf please |
performance reportbuild id: 126 timestamp: Thu Mar 24 10:53:02 UTC 2022 results
comparison
|
Signed-off-by: Si Beaumont <beaumont@apple.com>
|
@swift-nio-bot test perf please |
|
!!! Couldn't read commit file !!! |
|
We have a winner... test 57: Looking at the change between this PR and $ git show origin/main:Sources/NIOPerformanceTester/main.swift | grep -o "desc: .*" | sed 's|.*\"\(.*\)\".*|\1|g' | grep schedule
schedule_10000_tasks
schedule_and_run_10000_tasks@Lukasa looking at the report it looks like this took O(1ms) on main. The thing to note here is that the existing label isn't correct. Here is for _ in 0..<self.numTasks {
self.loop.scheduleTask(in: .hours(1)) {
counter &+= 1
}
} |
|
Definitely seems like it's busting a limit, though I'm a bit surprised to see that. I suspect it's going to be memory. Want to drop the task count back down to 100k? |
Signed-off-by: Si Beaumont <beaumont@apple.com>
|
@swift-nio-bot test perf please |
performance reportbuild id: 128 timestamp: Thu Mar 24 14:16:08 UTC 2022 results
comparison
significant differences found |
|
@Lukasa well that was fun... |
|
Great work though! |
|
@simonjbeaumont wrt to buffering, how is the performance test outputting? maybe it should flush more aggressively? the harness script is not doing anything to get in the way |
Yep. Address in #2072. |
A bit late to the party, but just want to mention that in my experience it might be useful to also drop e.g. the two worst runs before taking the average if you want better test stability. It would still capture any systemic regressions and/or improvements introduced in the remaining samples while removing most ad-hoc outliers caused by other noise on the test machine. |
Motivation:
The current running time of some of the performance benchmarks is O(1 ms) which can lead to low signal in the results. It would be better if these tests ran for O(10 ms).
Modifications:
NIOPerformanceTesterto aim for O(10 ms) measurements with the current code.execute_100k_taskswhich is still too quick but the CI cannot handle 1M tasks.Result:
Notes:
The scaling factors were determined by looking at the
currentcolumn from a recent report on #2059: