Repository navigation
Measure the share usage overhead as a median over warmed up rounds - #91
Merged
Merged
Conversation
ShareUsageOverhead_SingleEvidence failed on an Intel macOS runner in the release build at 0.1083 ms per call against a 0.1 ms limit, in a pass where the same job ran the same tests four and a half times slower than in its own first pass. Intel macOS is the slowest runner the test runs on. Over 16 earlier jobs it measured 0.0088 to 0.021 ms for one evidence and 2.14 to 4.85 ms for 1,000. Each limit is now about ten times the highest of those, 0.25 ms and 50 ms, so a runner slowed for the whole test still passes. The failure message lists every round, because the build log shows only the message.
The comment said each limit is about ten times the slowest runner's highest figure. That holds for the single pass figures the limits were set from, but the warmed up medians the test now checks are lower, so the ratio would read as wrong against them. The comment now says what the limits allow for, which is the slowest runner running five times slower than usual for the whole test.
Merged
The limits were set from the figures of the single pass test this branch replaces, which are higher than the medians the test now checks. Each limit is now ten times the highest median any runner has printed at its usual speed, 0.06 ms for one evidence and 30 ms for 1,000 evidence. Every call carries the same Evidence, so after the first call the tracker turns each call away as a repeat. The tests are renamed to say they time repeated Evidence, and a class comment says what the rounds measure. The printed figures and the log line are removed, because the build sends test output to files that no build log shows. The failure message and the results file carry the figures.
The full build of the last commit measured a median of 3.231 ms for 1,000 evidence on Intel macOS at its usual speed, so 30 ms was less than ten times the highest usual median. The limit is now 40 ms, and the comment says each limit is at least ten times that median.
The full build of the last commit measured a median of 0.0066 ms for one evidence on Intel macOS at its usual speed, so 0.06 ms was less than ten times the highest usual median. The limit is now 0.07 ms. The comment says each limit is about ten times that median, because each build can move the highest median a little.
The commit before this one changed nothing, because the file it was given still held the old limit and comment, so this commit makes the change its message describes. The full build of 9bd1ce1 measured a median of 0.0066 ms for one evidence on Intel macOS at its usual speed, so 0.06 ms was less than ten times the highest usual median. The limit is now 0.07 ms, and the comment says each limit is about ten times that median, because each build can move the highest median a little.
jwrosewell
marked this pull request as ready for review
November 13, 2026 22:20
This was referenced Nov 13, 2026
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.
Problem
ShareUsageOverheadTests.ShareUsageOverhead_SingleEvidencefailed on an Intel macOS runner in the release build of #112, which tookrcatd99b7acfintomain. It failed in run 43364257944, attempt 1, job MacOS_X64_Java_11, and passed when the failed jobs were run again in attempt 2.The job runs the test class twice, once with the unit tests and once in the performance step. The unit test pass ran both tests in 2.991 seconds and passed. The performance pass, 36 minutes later on the same runner, took 13.553 seconds for the same two tests and failed, so the runner was about four and a half times slower for the whole of that pass, not for one call. The ten other jobs that ran the test in that attempt measured 0.005 to 0.012 ms.
The test on
rctimes one pass of 10,000 calls (1,000 calls for the 1,000 evidence test) withSystem.currentTimeMillisand no warm up, and checks that one number against 0.1 ms (10 ms for 1,000 evidence). The highest figure Intel macOS printed in the 22 jobs that passed in the builds listed below is 0.0246 ms, so the limit left that runner about four times its highest passing figure.The 1,000 evidence test failed the same way before this draft was opened, at 13.345 ms against 10 ms, in job MacOS_X64_Java_17 of run 42645701438, attempt 1, the full build of #78. In the same attempt job MacOS_X64_Java_11 passed at 9.365 ms, in a performance pass that took 18.148 seconds against 3.873 seconds for its unit test pass.
A test that fails on timing needs a limit that fits the slowest runner it runs on, or a fix for whatever makes it slow, rather than another run. This draft measures so that one slow round cannot decide the result, and sets each limit from the medians every runner prints.
What the specification says
The usage sharing element specification, Processing says this in lines 120 to 123, at the latest commit to that file.
This test checks that a Process call through the usage sharing element stays cheap. The specification sets no figure, so the limits are set from what the runners measure.
What changed
One test file,
ShareUsageOverheadTests.java. No package code changes. The branch mergesrcatb78810ff(which adds #118, two Markdown files at the root) and changes only the test file against it.System.nanoTime, each over its own set ofFlowData, with closing them outside the timed part. The median round is checked, so one round slowed by a garbage collection no longer decides the result, whilst a cost on every call still does. The one evidence test makes 10,000 calls a round and the 1,000 evidence test makes 250.ShareUsageTracker.match), which is 20 minutes by default. So after the first call it turns each call away and nothing more is queued. The measured rounds time that path, whereShareUsageBase.processDataasks the tracker and the tracker finds the values the call would share to make its key. The tests are renamedShareUsageOverhead_RepeatedSingleEvidenceandShareUsageOverhead_RepeatedThousandEvidence, and a class comment says what the rounds time. The results keep their names,ShareUsageOverhead_SingleEvidence_msandShareUsageOverhead_HundredEvidence_ms, so they line up with those of earlier builds.System.out.printlncalls and the log line are gone, with the logger.pipeline/pom.xmlsetsredirectTestOutputToFile, so test output goes to files undertargetthat no build log shows, and the full log of job MacOS_X64_Java_17 in run 43382362370 runs the test and has noms per callline. The failure message and the results file carry the figures.The class now takes 3.9 to 16.6 seconds a pass in this draft's builds (18.0 seconds in the one slowed pass), against 1.9 to 9.5 seconds at usual speed for the single pass test. Each job runs it twice, so in the green build each job spent 2 to 10 seconds longer on it than the same job did in release build 43364257944, in jobs that took 20 to 75 minutes. That buys a figure that the JIT warming up and one slow round cannot move, which is what lets each limit sit about ten times above the medians rather than above one cold pass.
How each limit is set
Each limit is ten times the highest median any runner has printed at its usual speed, rounded up to one significant figure. A pass counts as at its usual speed when the test class took less than twice as long as in the same job's unit test pass. Every pass of this draft did except one, at 2.3 times, and the rest took 0.76 to 1.60 times as long. Intel macOS printed both of the highest usual medians, so the limits fit the slowest runner.
Ten is about twice the largest slowdown seen for a whole pass, 4.7 times in job MacOS_X64_Java_11 of run 42645701438, so a runner that slow still passes. The test fails when the median per call reaches 10.6 times (one evidence) or 12.4 times (1,000 evidence) the highest usual median. Growth below that passes, and shows only in the figures each performance step prints.
These are the slowest whole passes seen, each measured as the class time against the same job's unit test pass. Only the last is a median of this draft, and it is under its new limit.
Each runner's figures
This draft's median, in milliseconds per Process call, lowest to highest over the jobs counted, from the
LowerIsBetter.ShareUsageOverhead_SingleEvidence_msandLowerIsBetter.ShareUsageOverhead_HundredEvidence_mslines the performance step prints. The second is the 1,000 evidence test, whose result keeps its older name.ubuntu-22.04ubuntu-22.04-armwindows-2025-vs2026macos-15-arm64macos-15These come from the full builds 42717428349 on
fed3a83b, 43382362370 and 43411790985 (both attempts) onb96922b1, 43437941585 ondb7e36cf, 43457504599 on9bd1ce1cand 43499659322 on6ca326e3. Every one measured the same way, because the later commits change only the limits, the failure message, the names, the comments and the output.For comparison, the single pass test before this draft printed these figures in jobs that passed.
ubuntu-22.04ubuntu-22.04-armwindows-2025-vs2026macos-15-arm64macos-15Every runner's figures come from the release builds of
rcat9a668883,6644140aandd99b7acf(43130836772, 43151568806 and 43364257944, both attempts). Intel macOS's also come from attempt 1 of the full build of #78's head90eac597(42645701438) and from every attempt of the nightly runs 42747966370, 42951328299 and 43146786827. Those nightly jobs buildmain, apart from the three Build and Test jobs of run 42951328299, which build the head of #103,93568c50.Builds
Red, the test before this draft. Run 43364257944, attempt 1 on
rcfailed at 0.1083 ms against 0.1 ms, and run 42645701438, attempt 1 on the head of #78 failed at 13.345 ms against 10 ms, as described above.Green. Full build run 43499659322 of
6ca326e3passed on all 15 jobs in attempt 1, macOS included, and every job'sSetting 'PullRequestSha'line is6ca326e3139db4b77d02892509fea9944f02c6d4.ubuntu-22.04ubuntu-22.04ubuntu-22.04ubuntu-22.04ubuntu-22.04-armwindows-2025-vs2026windows-2025-vs2026windows-2025-vs2026windows-2025-vs2026macos-15-arm64macos-15-arm64macos-15-arm64macos-15macos-15macos-15Earlier builds of this branch. Run 43437941585 of
db7e36cfand run 43457504599 of9bd1ce1ceach passed on all 15 jobs in attempt 1. Their medians of 3.231 ms (1,000 evidence) and 0.0066 ms (one evidence), both from MacOS_X64_Java_17 at its usual speed, raised the highest usual medians, so the commits after them raised the 1,000 evidence limit from 30 ms to 40 ms and the one evidence limit from 0.06 ms to 0.07 ms. Commit26a51a41, after9bd1ce1c, changes nothing, because the file it was given still held 0.06 ms. Its build, run 43499485416, was cancelled, and the commit after it,6ca326e3, makes that change.Two failures that are not this change. Both were on Intel macOS, in tests that do not run the one file this draft changes, and
ShareUsageOverheadTestspassed in the unit test step of both failing jobs.b96922b1failed on job MacOS_X64_Java_17 infiftyone.geolocation.data.tests.FiftyoneValueTests, the geo-location cloud value tests.ValueTests_Cloud_AvailablePropertiesspent 30.63 seconds before processing raisedAggregateException: Exception(s) occurred processing evidence., and the other two tests raised the same within 0.02 seconds. The Cloud Request Engine's default request timeout is 2 seconds. The same tests passed on the twelve jobs of that build that completed, including MacOS_X64_Java_11 on the same image and head in 3.4 seconds, and on MacOS_X64_Java_21 in 3.5 seconds before the failure cancelled it. No other run among this repository's 40 most recent failed runs, back to 11 November, shows them failing. The log does not carry the exception's causes, so it does not say which request failed or why.Example_RendersClientSideOverridesOnThePagegave up after 60 seconds waiting for the browser driver to load the page (The HTTP request to the remote WebDriver server for URL http://localhost:49484/session/9a336c17f263d38dbf1b8527e8d7fff6/url timed out after 60 seconds). The other eight tests against the cloud example passed, and all nine against the on-premise example passed straight after. The four macOS jobs that failure stopped passed when run again in attempt 2.Remains