Measuring an XCUITest Suite Before You Speed It Up

Parts 1 to 6 of this series are about making UI tests correct. Parts 7 to 11 are about making them faster without making them less correct. This part covers the groundwork: how to measure a suite so that a later change can be shown to have helped, and shown not to have broken anything. Each section explains one measurement question, gives the practical steps, and closes with do's and don'ts. The figures come from a production SwiftUI app with a macOS lane of 315 tests and iPhone and iPad lanes of about 230 each.

The four numbers to collect first

A UI-test suite has a wall clock, but a wall clock alone cannot tell you where time goes or whether a change helped. Four numbers together can.

1. The wall clock of one whole run, timed around the xcodebuild invocation. This is the number people care about, and the least precise.
2. The per-test median, read from the result bundle. Medians resist a single hung test; averages do not.
3. The setUp breakdown: how long launch, provisioning and login take before the first line of a test body runs. This shows what every test pays regardless of what it asserts.
4. The pass set: which tests passed, failed and skipped, by test id. This is the number that makes the other three trustworthy.

For the macOS lane in this series, those numbers were: a 22,486 second run (6 hours 15 minutes) for 315 tests, a 58.6 second median per test, and a 39.1 second median setUp made up of 5.1 seconds of launch and idle, 0.9 seconds of provisioning a test tenant and 33.1 seconds of typing a login. The pass set was 303 passed, 4 failed, 8 skipped. Every performance change in parts 8 to 11 is compared against these.

The setUp breakdown deserves a note, because it is the number that ranks the candidate fixes. In this suite the typed login was 84 percent of setUp, which made the per-class app lifecycle of part 8 the first thing to try. The provisioning step, which a call-site count had suggested was expensive, was 2 percent, and caching it was dropped (part 11). The breakdown is read from the result bundle's activity tree: the timestamps of the first activity after setUp begins, the launch activity, and the first activity of the test body.

Getting a run that can be reported

Before a run can be measured, it has to finish, and every test in it has to have an outcome. Three xcodebuild options make that happen.

LEG=full-mac-$(date +%Y%m%d)
START=$SECONDS
xcodebuild test -workspace "App.xcworkspace" -scheme App-macOS \
  -destination platform=macOS -allowProvisioningUpdates \
  -enableCodeCoverage NO \
  -test-timeouts-enabled YES \
  -default-test-execution-time-allowance 600 \
  -maximum-test-execution-time-allowance 900 \
  -resultBundlePath /tmp/legs/$LEG.xcresult 2>&1 | tee /tmp/legs/$LEG.log
WALL=$(( SECONDS - START ))

• -test-timeouts-enabled YES with an execution time allowance turns a hung test into a named failure. Without it, one hung method can consume the rest of the run and the log simply stops. A sensible default allowance is a few times the longest healthy test on record; here 600 seconds is about four times the 148 second maximum.
• The maximum allowance is the ceiling no individual test can raise above, for classes that set their own.
• -enableCodeCoverage NO avoids a hang that is easy to misread: coverage-profile collection can block on a privacy prompt for the app container, and the run prints that testing started and never prints that it finished.
• The wall clock is measured around the whole invocation. Summing per-test durations from the bundle leaves out build, install, teardown and runner restarts, so it is not a substitute.

The difference these flags make is visible in one before/after pair from this suite. The run before them lasted 8,234 seconds, started 302 tests, lost 82 to rate-limit skips and 20 to runner crashes, and ended with a log that stopped mid-run. The run after them had zero crashes, zero rate-limit skips, and every hang was a named 600 second failure.

Do

• Give every run its own result bundle path, and keep the bundle. It is the source for every number below.
• Run one xcodebuild at a time on a machine. A second one, or another test runner, is contention, and the run it overlaps is not comparable.
• Scope by class with -only-testing:Target/ClassName, and check that the number of tests started matches the number you expected.

Don't

• Don't run a leg without timeouts if you intend to record it.
• Don't pass a file stem to -only-testing. It takes a class name; a file name selects nothing and xcodebuild does not complain.
• Don't record a wall clock derived from summed test durations.

Reading outcomes from the result bundle

The result bundle is read with xcresulttool. Two commands cover most needs: one for per-test outcomes and durations, one for the activity tree that shows where a test's time went.

# per-test outcome, duration and skip reason
xcrun xcresulttool get test-results tests --path /tmp/legs/$LEG.xcresult

# the activity tree for one test: launch, waits for idle, taps, each with a timestamp
xcrun xcresulttool get test-results activities --path /tmp/legs/$LEG.xcresult \
  --test-id "AppUITests/CustomerFlowTests/test_createCustomer()"

When turning this into a table, three details matter. A test with no duration in the bundle should be recorded as missing, not as zero; skipped tests routinely omit the field, and treating it as 0.0 pulls every median down exactly when skips rise. A bundle with no tests in it should be treated as an error rather than a run with zero time. And a test that ran and failed still counts as having run, which is the subject of the next section.

Ran is not passed

The most common way to mis-read a performance run is to count tests that ran and asserted, and treat that count as a pass count. In this suite, one run was recorded as 307 green out of 315 started. Reading the same bundle test by test gave 303 passed and 4 failed. A later comparison then attributed one of those failures to a new change, because it had compared durations and never compared outcomes.

A comparison tool built on the same counts has the same blind spot. One that checked for falling ran-and-asserted counts, rising skips and missing tests reported a leg as 81.3 percent faster with exit code 0, on a run in which 5 of 10 tests had failed. All five had run and asserted, so none of the checks fired.

One arithmetic detail is worth knowing in advance. When a change converts a by-design failure into a skip, three totals move at once: ran goes down by one, skipped goes up by one, failed goes down by one. A count-based comparison reads two of those as regressions. Writing down the expected arithmetic before the run avoids arguing about it after.

Do

• Compare outcome sets by test id, before and after.
• Treat a missing duration as missing and a test-less bundle as an error.
• Keep the run log as well as the bundle; the log is the place to grep for rate-limit and crash signatures.

Don't

• Don't use ran-and-asserted as a pass count.
• Don't accept a change on a comparison tool's exit code.
• Don't read outcomes from the log. It has two spellings for a failed test, not every outcome appears in both, and a runner restart after a timeout is not a crash.

When a before/after comparison is valid

A before/after pair is only comparable when both halves were produced under the same conditions: one machine, one server release, one session, and a host that was not busy with something else. The last condition is the one most often broken on a developer machine, and the one hardest to see after the fact.

An example of what foreign load does to a run: one after-half in this suite ran beside a video call, a browser rendering process and a one-minute load average of 24. Every untouched test in the control class read 3 to 8 seconds slower than the before-half, and three tests failed on 60 to 107 second hittability stalls. All three passed on their own afterwards, on the same build. The run's contention check had passed, because it only looked for other xcodebuild processes.

Sample the host, and set thresholds as a share of capacity

The practical answer is to sample the host once a minute beside every run (ps for per-process CPU, plus the load average), and to write the thresholds as a share of the machine's capacity rather than as bare percentages. ps reports CPU per core, so 100 means one full core, and a bare 30 percent threshold on a 20-core machine is 1.5 percent of capacity; it will fire on every run and tell you nothing. The thresholds used for this series: a run's wall clock and class medians are not admissible when aggregate foreign CPU exceeds 25 percent of capacity, or when any single foreign process exceeds 15 percent. The run's pass set, and any per-wait bounds it measured, still stand, because those do not depend on the host.

• Use the aggregate, not the largest process. Per-process figures fall as total load rises: 24 busy loops on 20 cores read 84 percent each, while 4 loops read 100.
• Treat load average as a saturation signal, not as attribution. It counts runnable threads without saying whose they are, and it lags: after 24 loops were killed and foreign load was back to one core, the one-minute average still read 36 to 39.
• Give WindowServer no threshold of its own. It read 0.0 percent during a real simulator run and 48.9 percent during a no-op control, because it tracks the desktop, and the simulator's own rendering flows through it. Count it in the aggregate.
• Attribute CPU by walking the run's own process tree, so the run is never charged for its own build. Anything that cannot be attributed counts as foreign.

Do

• Record machine, OS, Xcode version, simulator runtime and server release beside every run.
• Keep the measuring script unchanged for the duration of a before/after window. Improving it halfway makes the two halves products of different instruments.
• Keep the screen unlocked and the machine awake; on macOS, run the leg under caffeinate -dimsu. A run that straddles a screen lock is not admissible from the lock onward.

Don't

• Don't compare a run on one server release with a run on another without reading the release notes; a configuration change and a code deploy look the same in a version number.
• Don't claim a wall clock from a run that overlapped a contended host. Report the per-test bounds and the pass set instead, and say why.
• Don't type into any Mac app while a simulator run is in progress. The Simulator re-activates on every launch and the keystrokes land in the app under test.

Confirming which build you measured

A before/after pair almost always rebuilds the app between halves, so each half needs a way to prove which source it ran. The two obvious checks both fail.

• The binary's md5 changes between two builds of the identical source in different DerivedData folders, so a criterion written on it can never be satisfied.
• The binary's modification time can stay the same across a rebuild that changed the code; this was observed once, and once is enough to disqualify it.

What does work is the source tree's own identity plus a symbol the change introduced, counted in the built product with nm. Demangle first; strings cannot see a mangled Swift symbol.

git rev-parse HEAD^{tree}                          # identity of the source tree
nm "$BUILT_PRODUCT/App.debug.dylib" | swift demangle \
  | grep -c UITestingAnimationsOff                 # 0 before, 37 with the arm, 0 after revert

On the simulator lanes there is an additional step: the UI-test project may not build the app under test at all. If the xctestrun has no target app path, the run launches whatever build is installed on that simulator, however old. Build and install the app explicitly before each run, and compare the md5 of the built and the installed debug dylib to confirm they match. That md5 comparison is valid because it compares one build with itself, not two builds with each other.

Do

• Record the tree id and one symbol count per half.
• Delete the test DerivedData when a reported line number and its message disagree. A sub-two-second incremental build once produced a binary with a new string table and a stale line table.

Don't

• Don't identify a build by md5 across a rebuild, or by mtime at all.
• Don't grep the .app executable for a symbol; on the simulator it is a stub. Grep the debug dylib.

macOS automation cannot run unattended

One constraint applies to every macOS run and is easy to plan around once known: macOS does not allow UI automation to run blind. The system requires a person to allow the test runner to control the machine, and that approval is interactive. If nobody is at the device to grant it, or the screen is locked or asleep, the run fails during initialisation with Timed out while enabling automation mode after about 65 to 70 seconds, with a signed build, a launched runner and zero executed tests. This applies just as much when the run is started by a script or an agent: someone still has to be physically present at the Mac to approve it, and a run scheduled for a time when nobody is there will time out rather than run.

Do

• Plan macOS runs for when someone is at the machine to allow automation, and keep the screen unlocked and awake for the whole run (caffeinate -dimsu around the invocation).
• Read a zero-test timeout at initialisation as a host condition, not as a test result. Record the run as blocked, never as red.

Don't

• Don't schedule unattended macOS UI-test runs and expect them to execute.
• Don't call screencapture or any screen-recording API from the runner's process. It raises a system consent panel that only a person can clear, and every later run is unattributable. The result bundle's accessibility snapshots already record the screen.

Shell pitfalls that read as success

Several problems in a long measuring session came from shell mechanics rather than from XCTest, and none of them printed an error. They are listed here because each one cost a run.

• A waiter of the form until ! pgrep -f "scheme App" never returns, because its own command line matches the pattern. Poll the log for the terminal marker instead.
• The terminal marker differs by xcodebuild action: TEST BUILD SUCCEEDED for build-for-testing, TEST EXECUTE SUCCEEDED or FAILED for test-without-building, TEST SUCCEEDED or FAILED for test. Match all three, and remember the marker means finished, not green.
• zsh does not word-split an unquoted variable, so --workers 3 held in a variable arrives as one argument. Pass such flags literally or use an array.
• nohup inside a backgrounded command reports the wrapper's exit 0 and takes the detached xcodebuild down with it. Run a multi-hour leg under a supervisor the session cannot reap, and have it write its own done marker.
• Omitting -workspace in a repository root that contains two workspaces errors and still exits 0. Read exit codes directly, never through a pipe.

Checklist

1. Collect the wall clock, the per-test median, the setUp breakdown and the pass set before changing anything.
2. Run with timeouts enabled, coverage off, one xcodebuild at a time, and keep every result bundle.
3. Read outcomes by test id from the bundle; never from a ran-and-asserted count or a tool's exit code.
4. Compare only runs from one machine, one server release and one session, with the host sampled beside them.
5. Identify each half's build by tree id and symbol count.
6. On macOS, have someone at the machine to allow automation, and keep the screen unlocked and awake.

With these in place, a performance change can be judged on two things: an identical pass set, and a delta measured under comparable conditions. Part 8 applies that to the largest cost in the setUp breakdown, the launch and login every test pays.

Previously (Part 6): Diagnosing a Red XCUITest: Environment, Order, and Process

Next up (Part 8): The Launch-and-Login Tax: Per-Class App Lifecycle in XCUITest