From 4c96d63ca00f0eb645426c8ee0e3b0fdb2498bb9 Mon Sep 17 00:00:00 2001 From: Valentin Pertuisot Date: Fri, 21 Aug 2026 16:26:57 +0200 Subject: [PATCH 1/3] RUM-18135: Add the cold-start A/B benchmark harness MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Measuring what the SDK costs at app startup is easy to get wrong in ways that produce a confident number rather than an obviously broken one. Running the same APK in both arms on a mid-range device, an uncontrolled protocol reported +12.7 ms, 95% CI [+3.0, +22.5], p = 0.011 — a significant regression between two identical builds. Every control here removes a failure mode that produced a wrong number, not one we imagined. verify_sdk_active.sh step zero: installs, md5-attests the install, launches via the real launcher intent and proves Datadog actually initialized. A build that CONTAINS the SDK is not necessarily one that INITIALIZES it, and an arm that was inert invalidates everything measured against it. The oracle is the `datadog-*` thread CoreFeature.initialize() always creates and R8 cannot rename. coldstart_bench.sh the A/B. ABBA-counterbalanced blocks, md5 attestation per install, pre-granted runtime permissions, pre-registered warm-up discard, and a per-launch assertion that the launch was COLD and the app owned the foreground. Aborts rather than recording a sample it cannot vouch for. ab_stats.py statistics. The primary endpoint is a paired test over per-block deltas, because launches inside one arm×block cell share an install, an AOT compilation and a thermal state; pooling them estimates the SE from within-cell scatter only. The Welch figures are printed as [diagnostic] for contrast. fp_simulation.py reproduces the false-positive table that justifies that choice, driving ab_stats.py's own interval code so the published numbers cannot drift from the tool. lib.sh shared helpers: resolves adb/aapt2 without depending on PATH, refuses to measure a locked device, and matches both `mResumedActivity` and the bare `ResumedActivity:` some vendors print. Both device-touching scripts snapshot every setting they change and restore it from an EXIT trap, revoke only the permission grants they made themselves, and treat Ctrl-C as "stop and restore" rather than "restore and keep going". --- tools/coldstart-benchmark/.gitignore | 6 + tools/coldstart-benchmark/README.md | 250 ++++++++ tools/coldstart-benchmark/ab_stats.py | 527 ++++++++++++++++ tools/coldstart-benchmark/capture_trace.sh | 322 ++++++++++ tools/coldstart-benchmark/coldstart_bench.sh | 582 ++++++++++++++++++ tools/coldstart-benchmark/fp_simulation.py | 110 ++++ tools/coldstart-benchmark/lib.sh | 219 +++++++ .../coldstart-benchmark/verify_sdk_active.sh | 146 +++++ tools/coldstart-benchmark/verify_trace.py | 257 ++++++++ 9 files changed, 2419 insertions(+) create mode 100644 tools/coldstart-benchmark/.gitignore create mode 100644 tools/coldstart-benchmark/README.md create mode 100755 tools/coldstart-benchmark/ab_stats.py create mode 100755 tools/coldstart-benchmark/capture_trace.sh create mode 100755 tools/coldstart-benchmark/coldstart_bench.sh create mode 100755 tools/coldstart-benchmark/fp_simulation.py create mode 100755 tools/coldstart-benchmark/lib.sh create mode 100755 tools/coldstart-benchmark/verify_sdk_active.sh create mode 100755 tools/coldstart-benchmark/verify_trace.py diff --git a/tools/coldstart-benchmark/.gitignore b/tools/coldstart-benchmark/.gitignore new file mode 100644 index 0000000000..b38b39a2ea --- /dev/null +++ b/tools/coldstart-benchmark/.gitignore @@ -0,0 +1,6 @@ +__pycache__/ +*.pyc +results_*.csv +bench_*.log +*.pftrace +.venv/ diff --git a/tools/coldstart-benchmark/README.md b/tools/coldstart-benchmark/README.md new file mode 100644 index 0000000000..3f45877ea3 --- /dev/null +++ b/tools/coldstart-benchmark/README.md @@ -0,0 +1,250 @@ +# Cold-start benchmark harness + +Measures how much cold-start time the Datadog Android SDK adds to a host application, with +the controls needed to make the answer trustworthy. + +**Full guide, including how to interpret the output:** +[`docs/benchmarking_sdk_cold_start.md`](../../docs/benchmarking_sdk_cold_start.md). This +file is the operator's reference for the scripts themselves. + +> [!WARNING] +> **All three device-touching scripts — `verify_sdk_active.sh`, `coldstart_bench.sh` and +> `capture_trace.sh` — uninstall and reinstall the app under test**, which deletes all its +> data. That includes the step-zero verifier, so running it against an app you care about +> destroys its state. `coldstart_bench.sh` and `capture_trace.sh` also pre-grant the app's +> runtime permissions. +> `coldstart_bench.sh` also changes device settings (animation scales, screen timeout, +> stay-awake, Wi-Fi). Both snapshot everything they touch and put it back on exit — including on +> Ctrl-C, which stops the run — and both revoke only the permission grants they made themselves, +> never device-wide. Use a test device. + +## Why the extra machinery + +A cold-start A/B without these controls produces numbers wrong by more than the effect +measured. Running the **same APK in both arms** (true delta zero) on a mid-range device: + +| protocol | reported "difference" | 95% CI | p | +|---|---|---|---| +| fixed arm order, permission dialogs unhandled | +12.7 ms | [+3.0, +22.5] | **0.011** | +| counterbalanced, dialogs unhandled | +5.0 ms | [−4.4, +14.4] | 0.30 | +| counterbalanced + permissions pre-granted | −0.8 ms | [−6.9, +5.2] | 0.79 | + +Most of these controls fix a failure mode we hit and measured; the rest are cheap +insurance against one that would be invisible after the fact. + +## Two prerequisites that decide whether your numbers mean anything + +**Build both APKs release-configured.** `isMinifyEnabled = true`, `isDebuggable = false`, +release signing, production R8 rules, no debug-only tooling (LeakCanary, Chucker, Stetho, +Flipper). A debug build's startup behaviour has little to do with what your users experience. + +**Run on a physical device.** Emulator results are effectively worthless here — a laptop core +is many times faster than a mid-range phone core, backed by an SSD rather than eMMC, with no +big.LITTLE scheduling and no thermal throttling. Those differences land squarely on native +library loading, dex verification, disk I/O and thread contention. There is no correction +factor that recovers the real answer. Pick a device that resembles your actual user +distribution, not the newest phone on the team's desk. + +## Requirements + +- `adb` on `PATH`, or `ANDROID_HOME` / `ANDROID_SDK_ROOT` set, or `ADB=/path/to/adb` +- `aapt2` (Android SDK build-tools), or `AAPT2=/path/to/aapt2`. **Required**, not optional: + it is what proves the APKs declare the `PKG` that `adb uninstall` is about to wipe +- exactly one authorized device attached (`adb devices` shows `device`, not `unauthorized`). + With several attached, set `ANDROID_SERIAL=` +- the device **unlocked and on the home screen**. A locked device resumes the activity but + never draws, so `am start -W` reports no `TotalTime` and `LaunchState=UNKNOWN`; + `coldstart_bench.sh` refuses to start rather than collect unusable rows. `adb` cannot + dismiss a PIN/pattern/password lock +- **Python ≥ 3.8** for `ab_stats.py` and `fp_simulation.py`. No third-party packages needed +- the `perfetto` package, **only** for the trace scripts: + ```bash + python3 -m venv .venv && ./.venv/bin/pip install perfetto + ``` + `capture_trace.sh` finds this venv on its own. When running the verifier by hand, pass the + venv interpreter explicitly — `verify_trace.py`'s shebang is `#!/usr/bin/env python3`, i.e. + your system Python, which will not see the venv: + ```bash + ./.venv/bin/python verify_trace.py treatment.pftrace --package "$PKG" + ``` +- two **release-configured** APKs of the same app version (matching + `versionCode`/`versionName`), differing only by the Datadog SDK + +## Files + +| file | role | +|---|---| +| `verify_sdk_active.sh` | **run this first** — proves the SDK actually initializes on-device. Uninstalls/reinstalls, so it deletes app data | +| `coldstart_bench.sh` | the A/B (or A/A) benchmark | +| `ab_stats.py` | statistics: paired per-block delta (primary), Welch and permutation tests (diagnostic), per-block drift, block-paired order effect, MDE / required blocks. `--metric total_ms\|displayed\|ttfd` selects the measurement window. Refuses to pool CSVs from different devices or protocols (`--allow-mixed`), and refuses aborted or truncated runs — it checks the block/cell counts against the header, so a `kill -9` that skipped the abort marker is still caught (`--allow-aborted` for diagnostics) | +| `capture_trace.sh` | Perfetto capture with attestation and liveness gating | +| `verify_trace.py` | decides whether a trace shows the SDK running — and whether it *can* answer that at all. `--require-foreground` additionally fails (exit 4) a capture the app did not own for the *whole* window, which an end-of-capture check cannot see | +| `fp_simulation.py` | reproduces the false-positive table below, using `ab_stats.py`'s own interval code | +| `lib.sh` | shared helpers; resolves `adb` and `aapt2` without depending on `PATH` | + +## Usage + +```bash +export PKG=com.example.app + +# 1. Prove the SDK initializes. Nothing else matters if this fails. +./verify_sdk_active.sh app-with-datadog.apk "$PKG" + +# 2. Validate the protocol: same APK both arms, expect a null result. +EXPECT_B=0 LABEL_A=A1 LABEL_B=A2 \ + ./coldstart_bench.sh app-no-datadog.apk app-no-datadog.apk +./ab_stats.py results_.csv --baseline A1 --treatment A2 + +# 3. The real comparison. +./coldstart_bench.sh app-no-datadog.apk app-with-datadog.apk +./ab_stats.py results_.csv + +# 4. Optional: attribute the cost. +./capture_trace.sh app-with-datadog.apk treatment 1 +./.venv/bin/python verify_trace.py treatment.pftrace --package "$PKG" +``` + +Each `coldstart_bench.sh` run prints the `results_.csv` it wrote; pass that path +to `ab_stats.py`. A `coldstart-benchmark` skill under `.claude/skills/` drives these same +steps if you are working through a coding agent. The A/A run in step 2 sets `EXPECT_B=0` because both arms are the baseline +APK; to A/A the treatment APK instead, use `EXPECT_A=1 EXPECT_B=1`. + +Arguments are ` [runs-per-block] [blocks]`, defaulting to +**4 runs × 8 blocks** — 32 measured launches per arm, and roughly an hour on a mid-range +device. `blocks` must be even, for ABBA counterbalancing. + +**Add blocks, not runs, when a result is underpowered.** The primary endpoint is a paired +test over per-block deltas, so the confidence interval narrows with the square root of the +number of *blocks*. Fewer than 3 complete blocks and `ab_stats.py` refuses to report an +interval at all. + +### Environment variables + +| var | default | meaning | +|---|---|---| +| `PKG` | *required* | your application id | +| `EXPECT_A` / `EXPECT_B` | `0` / `1` | per-arm SDK-liveness expectation; set `EXPECT_B=0` for an A/A run of the baseline APK. A value other than `0`/`1` is rejected rather than silently disabling the gate | +| `LABEL_A` / `LABEL_B` | `A_noDD` / `B_withDD` | arm labels in the CSV | +| `WARMUP` | `3` | discarded launches at the start of each arm×block cell. Pre-registered: nothing else is ever dropped | +| `COMPILE_FILTER` | `speed-profile` | AOT filter. `speed-profile` is what Play installs converge to. `speed` gives lower variance but removes much of the class-load/verify cost the SDK contributes and overrides any Baseline Profile — use it as a secondary run, not a headline | +| `APP_TRACE_REGEX` | unset | an ERE matching a log line where your app reports its **own** startup duration; the last number in the match is recorded per launch as `app_trace_ms` and is analysable with `--metric app_trace_ms`. Use this to A/B the metric your team already quotes, e.g. `APP_TRACE_REGEX='cold_launch total duration: [0-9]+'`. Check first that the trace actually emits, and that it ends where you think — one app's "first frame" trace ran 140 ms past `am start -W TotalTime` | +| `ANIMATIONS` | `0` | animation scales during the run. `0` removes a large variance source but **understates any per-frame SDK cost** (vitals / long-task `Choreographer` callbacks, Session Replay snapshots) because fewer frames are drawn during the launch. `1` measures with animations on; the value is stamped into the CSV header. Run both to quantify the bias | +| `AIRPLANE` | `0` | `1` disables Wi-Fi and mobile data via `svc`, as a variance sanity check. Not airplane mode; `svc data disable` needs root on most retail devices | +| `ALLOW_VERSION_MISMATCH` | `0` | `1` lets the preflight through when the two APKs declare different `versionCode`/`versionName`. Only use it if you know why they differ — otherwise the SDK is not the only variable between the arms | +| `ALLOW_UNVERIFIED_PKG` | `0` | `1` disables the APK↔`PKG` check entirely (both scripts). Only for the case where `aapt2` is genuinely unavailable **and** you have confirmed the package by hand — every block runs `adb uninstall $PKG` | +| `ANDROID_SERIAL` | unset | target a specific device when more than one is attached | +| `ADB` / `ANDROID_HOME` / `ANDROID_SDK_ROOT` | auto-detected | tool locations | +| `SETTLE` | `20` | `verify_sdk_active.sh` only: seconds to wait after launch before sampling threads | +| `ANIMATIONS` / `AIRPLANE` (trace) | `0` / `0` | `capture_trace.sh` honours both — set them to whatever the A/B used. A trace taken online cannot explain a delta measured offline, and one taken with animations off omits the per-frame SDK work an `ANIMATIONS=1` benchmark included | + +## What the benchmark does per arm, per block + +1. uninstall, install, and **md5-attest** the install against your local file +2. `cmd package compile -m $COMPILE_FILTER -f` for a stable AOT profile +3. pre-grant every runtime permission the app declares, recording each grant so that exactly + those — and nothing else on the device — are revoked when the run exits +4. probe `/proc//task/*/comm` and **abort** if SDK liveness contradicts the arm's + expectation +5. `WARMUP` launches, recorded as `phase=warmup` and excluded from analysis +6. `RUNS` measured launches via the real launcher intent, aborting if any is not + `LaunchState=COLD` / `Status=ok`, or if the app is not the foreground activity afterwards +7. thermal snapshot after each block + +Before any of that, a preflight reads both APKs with `aapt2` and refuses the run if they +declare a different application id from `PKG` (every block runs `adb uninstall $PKG`) or +different `versionCode`/`versionName` from each other (then the SDK is not the only variable). +`ALLOW_VERSION_MISMATCH=1` overrides the second. A missing `aapt2` is a **hard failure**, not a +warning: skipping the check because a tool is absent trades a fixable setup problem for an +unrecoverable one. `capture_trace.sh` applies the same package check before its own uninstall. + +The launcher activity is resolved **after each install**, from the build just installed — never +once up front. `resolve-activity` asks the package manager about the *installed* app, so hoisting +it made the harness unusable on a clean device and, worse, let it reuse a component read off a +leftover build. If the two arms resolve different components the run aborts: they would not be +entering through the same path. + +Arm order is counterbalanced across blocks (odd blocks baseline→treatment, even blocks +treatment→baseline) and each launch's position is recorded, so `ab_stats.py` can test for an +ordering bias rather than assume it away. Device settings are snapshotted before the run and +restored from an `EXIT` trap; `INT`/`TERM` exit into it, so Ctrl-C stops the run and restores +the device exactly once. + +## Output + +`results_.csv` — one row per launch, warm-ups marked rather than deleted: + +``` +# device=... sdk=... abi=... emulator=0 compile_filter=... blocks=... runs=... warmup=... fp=... launcher=... airplane=0 +label,block,pos_in_block,phase,run,total_ms,launch_state,status,foreground,displayed,ttfd,app_trace_ms,dd_enabled,dd_native_init_ms,dd_rn_init_ms +``` + +| column | meaning | +|---|---| +| `label` | arm (`LABEL_A` / `LABEL_B`) | +| `block`, `pos_in_block` | block number, and whether this arm ran 1st or 2nd within it | +| `phase` | `warmup` (excluded) or `measure` | +| `run` | launch index within the phase | +| `total_ms` | `am start -W` `TotalTime` — the primary metric | +| `launch_state`, `status` | `am start -W` `LaunchState` / `Status`; a measured launch that is not `COLD`/`ok` aborts the run | +| `foreground` | `ok` if the app was the resumed activity after the launch, else `OTHER` | +| `displayed` | logcat `ActivityTaskManager: Displayed` (TTID). Anchored on the AOSP format — some vendors log their own line first | +| `ttfd` | logcat `Fully drawn`, present only if the app calls `reportFullyDrawn()`. `NA` on every row usually means the app never reached its own ready state (a pending permission dialog will do it), not that the metric is unavailable | +| `app_trace_ms` | the app's own reported duration, if `APP_TRACE_REGEX` was set | +| `dd_enabled`, `dd_native_init_ms`, `dd_rn_init_ms` | populated only if the host app logs its own initialization state and timing | + +`bench_.log` — preflight assertions, per-arm thread counts and thermal snapshots. + +Emulator runs are stamped `emulator=1` and `ab_stats.py` prints a warning banner — emulator +timings are for harness validation only, never for reporting. + +## Interpreting results + +- **The paired per-block delta is the primary endpoint.** The unpaired Welch figures are + printed as `[diagnostic]` and are anti-conservative: launches within one arm×block cell + share an install, an AOT compilation and a thermal state, so pooling them estimates the + standard error from within-cell scatter only. At a realistic 4 ms between-block shift, a + 2×15 unpaired design false-positives 23% of the time against a nominal 5%. Run + `./fp_simulation.py` to reproduce that. +- CI includes zero → no regression demonstrated. The interval's upper bound is your + defensible upper bound. +- mean and median disagree materially → skewed; quote neither alone. +- per-block deltas falling either side of zero is **normal** when the effect is comparable to + the between-block sd — judge the spread by the CI and the MDE, not by counting signs. For an + A/A run in particular, deltas that all share a sign are evidence of a directional bias, not + of a clean protocol. +- always check the printed MDE before believing a null result. +- **On a framework app, analyse `--metric ttfd` as well as the default `total_ms`.** TTID + ends at first frame; if the app calls `reportFullyDrawn()` this is the only way to see + cost landing in the later window. Measured on one React Native app, TTID was ~630 ms + against a TTFD of ~2075 ms — first frame was under a third of startup, so TTID alone + could not have seen an SDK cost in the remaining two thirds. + +## Known limits + +- The metric is a **process-cold, page-cache-warm** start to first frame. `am force-stop` + does not evict the page cache, so by the first measured launch the app's dex, oat and + native libraries are resident — this protocol sees very little of the SDK's page-in cost. +- `am start -W TotalTime` ends at **first frame**. For React Native and Flutter apps much of + startup follows, so this understates any cost landing later. Have the app call + `reportFullyDrawn()` so `ttfd` is populated too. +- Several controls (forced AOT, discarded warm-ups, TTID-only, pre-granted permissions) bias + the measured SDK cost *downward*. The direction of each is tabulated in the + [guide](../../docs/benchmarking_sdk_cold_start.md#which-controls-bias-the-result-and-in-which-direction). +- `dumpsys thermalservice` returns stubbed values on some devices; a flat reading is not + evidence of no drift. +- Content variance is absorbed by n and counterbalancing for the A/B, but **not** for single + traces — keep the app on the same screen/state across trace captures. Expect the same window + to vary by hundreds of milliseconds of CPU between two captures of the *same* APK: use traces + to find out what work exists and where, and the A/B for how much it costs. +- A trace is only comparable to a benchmark launch if the app owned the foreground for the whole + capture. `capture_trace.sh` pre-grants runtime permissions and fails the capture if anything + else was on top at the end, because SDK liveness verification does not catch this — a paused + or stopped app still has all of its `datadog-*` threads, it just stops producing frames and + never reaches `reportFullyDrawn()`. +- Keep the screen awake for the whole session. `capture_trace.sh` restores the screen timeout it + found, so back-to-back captures on a device with a short timeout and a PIN will re-lock in the + gap and every run after the first dies on the lockscreen check. Raise `screen_off_timeout` and + `stay_on_while_plugged_in` yourself before a batch, and put them back afterwards. +- `capture_trace.sh` records **device-wide** process, thread and window data from every + running app. Review a trace before sharing it. +- Never compare emulator to device, or across device models. diff --git a/tools/coldstart-benchmark/ab_stats.py b/tools/coldstart-benchmark/ab_stats.py new file mode 100755 index 0000000000..c1dc16b60b --- /dev/null +++ b/tools/coldstart-benchmark/ab_stats.py @@ -0,0 +1,527 @@ +#!/usr/bin/env python3 +# Unless explicitly stated otherwise all files in this repository are licensed +# under the Apache License Version 2.0. +# This product includes software developed at Datadog (https://www.datadoghq.com/). +# Copyright 2016-Present Datadog, Inc. +""" +Statistics for a cold-start A/B run set produced by coldstart_bench.sh. + +PRIMARY ENDPOINT: the paired block-level delta. +----------------------------------------------- +Launches are not independent. They are collected in contiguous arm x block cells +(uninstall -> install -> AOT compile -> warm-ups -> N measured launches). Anything +that shifts a whole cell -- thermal state, dexopt, install recency, background +work -- is a cell-level random effect. Pooling all launches and running an +unpaired test estimates the standard error from WITHIN-cell scatter only and +ignores BETWEEN-cell variance, so it is anti-conservative. + +Measured by simulation (true effect zero, within-launch sd 11 ms, per-cell shift +sd sigma_b), false-positive rate of the nominal-95% interval: + + design sigma_b=0 2 4 8 + 2x15 unpaired 4.8% 10.0% 23.4% 45.5% + 8x4 paired on blocks 4.8% 4.9% 5.0% 4.8% + +Reproduce with ./fp_simulation.py -- it drives the interval code in this module, +so the table cannot drift away from what the tool actually does. + +Counterbalancing (ABBA) removes the ordering BIAS; it does nothing about this +variance underestimate. So the primary analysis here computes one delta per +block and runs a paired test on those. The unpaired Welch result is still shown, +labelled [diagnostic], because it is what most tools report and the contrast is +informative. + +Usage: ab_stats.py [more.csv ...] [--baseline A] [--treatment B] + [--metric total_ms|displayed|ttfd] + +METRIC CHOICE MATTERS on framework apps. `total_ms` (and the identical `displayed`) +end at first frame. For React Native / Flutter apps a large part of startup runs +after that, so an SDK cost landing in the later window is invisible to TTID. If the +app calls reportFullyDrawn(), `--metric ttfd` measures through to it. Report both. +""" +import argparse +import csv +import math +import random +import re +import statistics as st +from collections import Counter, defaultdict + +# Two-sided 97.5th percentile of Student-t. Keys are exact df. +_T = {1: 12.706, 2: 4.303, 3: 3.182, 4: 2.776, 5: 2.571, 6: 2.447, 7: 2.365, + 8: 2.306, 9: 2.262, 10: 2.228, 12: 2.179, 15: 2.131, 20: 2.086, + 25: 2.060, 30: 2.042, 40: 2.021, 60: 2.000, 120: 1.980} + +# One-sided 80th percentile of Student-t, i.e. the power term for 80% power. +_T80 = {1: 1.376, 2: 1.061, 3: 0.978, 4: 0.941, 5: 0.920, 6: 0.906, 7: 0.896, + 8: 0.889, 9: 0.883, 10: 0.879, 12: 0.873, 15: 0.866, 20: 0.860, + 25: 0.856, 30: 0.854, 40: 0.851, 60: 0.848, 120: 0.845} + + +def _t_lookup(table, df, floor): + """Table lookup rounding df DOWN, so every quantile is conservative.""" + if df >= 120: + return floor + best = table[min(table)] + for k in sorted(table): + if k <= df: + best = table[k] + else: + break + return best + + +def t_crit(df): + """97.5th percentile of t. Rounds df DOWN so the interval is never too narrow.""" + return _t_lookup(_T, df, 1.96) + + +def t_power80(df): + """80th percentile of t. Rounds df DOWN so the MDE is never too optimistic.""" + return _t_lookup(_T80, df, 0.842) + + +def mde(sd_b, k): + """Smallest true block delta this design detects with 80% power at alpha=.05. + + (t_{.975,k-1} + t_{.80,k-1}) * sd_b / sqrt(k). The normal approximation + (1.96 + 0.84 = 2.8) is what you usually see, but at the block counts this + harness runs it understates the MDE by ~15% -- at k=8, 2.8 against 3.26. + An MDE that reads too small makes an underpowered null look stronger than it + is, which is the exact failure the number exists to prevent. + """ + return (t_crit(k - 1) + t_power80(k - 1)) * sd_b / math.sqrt(k) + + +def blocks_for(sd_b, target, cap=200): + """Blocks needed to bring the MDE down to `target` ms. Solved by search + rather than in closed form, because both t quantiles depend on k.""" + for k in range(3, cap + 1): + if mde(sd_b, k) <= target: + return k + return None + + +def welch(a, b): + m1, m2 = st.mean(a), st.mean(b) + v1, v2 = st.variance(a), st.variance(b) + n1, n2 = len(a), len(b) + se = math.sqrt(v1 / n1 + v2 / n2) + if se == 0: + return m2 - m1, 0.0, float("inf"), 0.0 + t = (m2 - m1) / se + df = (v1 / n1 + v2 / n2) ** 2 / ( + (v1 / n1) ** 2 / (n1 - 1) + (v2 / n2) ** 2 / (n2 - 1)) + return m2 - m1, se, df, t + + +def perm_p(a, b, stat=st.mean, iters=200_000, seed=42): + """Two-sided permutation p. Floored at 1/(iters+1): a permutation test can + never yield exactly zero, and printing 0.0000 would overstate the evidence.""" + random.seed(seed) + obs = abs(stat(b) - stat(a)) + pool = list(a) + list(b) + n = len(b) + hits = 0 + for _ in range(iters): + random.shuffle(pool) + if abs(stat(pool[:n]) - stat(pool[n:])) >= obs - 1e-12: + hits += 1 + return (hits + 1) / (iters + 1) + + +_DUR = re.compile(r"(?:(\d+)h)?(?:(\d+)m(?!s))?(?:(\d+)s)?(?:(\d+)ms)?$") + + +def parse_ms(raw): + """Parse a duration cell. Plain numbers are already ms; logcat writes the + Displayed/Fully-drawn values as '+702ms', '+2s308ms', '+1m2s30ms'.""" + if raw is None: + return None + raw = raw.strip().lstrip("+") + if raw in ("", "NA", "null"): + return None + try: + return float(raw) + except ValueError: + pass + m = _DUR.match(raw) + if not m or not any(m.groups()): + return None + h, mi, se, ms = (int(g) if g else 0 for g in m.groups()) + return float(((h * 60 + mi) * 60 + se) * 1000 + ms) + + +# Metadata whose disagreement makes two runs incomparable. Deliberately NOT +# blocks/runs/warmup -- concatenating a 4-block and an 8-block run of the same +# build on the same device is legitimate and is the reason multi-file exists. +# `launcher` belongs here: the harness itself aborts when two ARMS resolve +# different launcher components, so pooling two FILES that entered through +# different components would contradict the rule it enforces internally. +_MUST_MATCH = ("fp", "emulator", "compile_filter", "animations", "airplane", "abi", + "launcher") + + +def parse_meta(lines): + """Pull `key=value` pairs out of a run's `#` header line(s).""" + kv = {} + for ln in lines: + for tok in ln.lstrip("#").split(): + if "=" in tok: + k, _, v = tok.partition("=") + kv.setdefault(k, v) + return kv + + +def fmt_p(p, iters=200_000): + """perm_p() floors at 1/(iters+1) so it can never be zero. '%.5f' would still + render that floor as 0.00000, which reads as 'impossible' rather than 'below + the resolution of this many permutations'.""" + floor = 1 / (iters + 1) + return f"<{floor:.2g} (permutation floor)" if p <= floor else f"{p:.5f}" + + +def main(): + ap = argparse.ArgumentParser() + ap.add_argument("csv", nargs="+", help="one or more results CSVs (concatenated)") + ap.add_argument("--baseline", default="A_noDD") + ap.add_argument("--treatment", default="B_withDD") + ap.add_argument("--allow-aborted", action="store_true", + help="analyse a CSV the harness marked RUN ABORTED " + "(diagnostic only -- refused by default)") + ap.add_argument("--allow-mixed", action="store_true", + help="pool CSVs whose device/protocol metadata disagrees " + "(refused by default)") + ap.add_argument("--metric", default="total_ms", + choices=["total_ms", "displayed", "ttfd", "app_trace_ms"], + help="total_ms/displayed = time to initial display (default); " + "ttfd = time to fully drawn, needs reportFullyDrawn(); " + "app_trace_ms = the host app's own metric, captured via " + "APP_TRACE_REGEX") + a = ap.parse_args() + if a.baseline == a.treatment: + raise SystemExit( + f"--baseline and --treatment are both {a.baseline!r}. That compares an arm " + "against itself:\n every block delta is 0 and the result is a null that " + "looks convincing and means nothing.\n For an A/A run give the two arms " + "distinct labels (LABEL_A=A1 LABEL_B=A2).") + + # Parse each file SEPARATELY. Concatenating them fed later header lines to the + # reader as data, and merged "block 1" from different runs into one block. + per_file, meta, per_meta = [], [], [] + for path in a.csv: + body, own_meta = [], [] + with open(path, encoding="utf-8") as fh: + for ln in fh: + (own_meta if ln.startswith("#") else body).append(ln) + per_file.append((path, body)) + per_meta.append(own_meta) + meta.extend(own_meta) + if len(per_file) > 1: + print(f"[{len(per_file)} files: block ids are namespaced per file, so blocks from " + f"different runs are never merged]") + # Namespacing block ids stops blocks being merged; it does NOT make the runs + # comparable. Pooling launches from two device models, or from an + # animations-on and an animations-off run, yields one confidence interval + # over two different experiments. Refuse unless told otherwise. + metas = [parse_meta(m) for m in per_meta] + mismatched = {k: sorted({m.get(k, "?") for m in metas}) + for k in _MUST_MATCH + if len({m.get(k, "?") for m in metas}) > 1} + if mismatched: + lines = [f" {k}: {' vs '.join(v)}" for k, v in mismatched.items()] + if not a.allow_mixed: + raise SystemExit( + "refusing to pool CSVs whose runs are not comparable:\n" + + "\n".join(lines) + + "\n These describe different devices or different protocols, so a" + "\n single pooled interval over them is not a valid estimate of" + "\n anything. Analyse them separately, or pass --allow-mixed if you" + "\n genuinely intend to pool them and will caveat the result.") + print("[WARNING: --allow-mixed, pooling runs that disagree on:]") + for ln in lines: + print(ln) + for m in meta: + print(m.rstrip()) + + # Each banner is decided over ALL metadata lines, independently of the others. + # These were briefly chained together -- the emulator check ended up nested under + # the aborted branch and testing the loop variable, so it never fired on a normal + # completed emulator run, which is the case it exists for. + if any("emulator=1" in m for m in meta): + print("!" * 78) + print("!! EMULATOR DATA. Emulator timings do not transfer to real devices:") + print("!! native library loading, dex verification, disk I/O and thread") + print("!! contention are all distorted, and there is no thermal throttling.") + print("!! Do not report these as your app's startup cost.") + print("!" * 78) + + if any("RUN ABORTED" in m for m in meta): + print("!" * 78) + print("!! This CSV is a PARTIAL run: the harness aborted before finishing.") + print("!! Whatever it contains was not collected under the protocol as designed.") + print("!" * 78) + # Printing a banner and then computing a reportable interval anyway is the + # same mistake the whole design argues against: an aborted run can stop + # part-way through an arm, and the block logic accepts a cell with a single + # sample, so a rejected protocol could still produce a primary endpoint. + if not a.allow_aborted: + raise SystemExit( + " refusing to analyse an aborted run. Fix the cause and re-run.\n" + " If you need to inspect it anyway, pass --allow-aborted -- the output\n" + " is then diagnostic only and must not be reported as a result.") + print("[WARNING: --allow-aborted. This output is DIAGNOSTIC ONLY. Do not report it.]") + + # ---- does the CSV contain the experiment its own header describes? ---------- + # A `kill -9`, host crash or power cut bypasses the harness's EXIT trap, so the + # RUN ABORTED marker never gets written and a truncated file looks complete. The + # header records how many blocks and runs were requested, so compare against what + # is actually present rather than trusting the absence of a marker. + shortfalls = [] + for (path, body), own_meta in zip(per_file, per_meta): + kv = parse_meta(own_meta) + try: + want_blocks, want_runs = int(kv["blocks"]), int(kv["runs"]) + except (KeyError, ValueError): + continue # pre-metadata CSV; nothing to check against + cells = defaultdict(int) + for r in csv.DictReader(body): + if r.get("phase") in ("measure", "measure_rejected"): + cells[(r.get("label"), r.get("block"))] += 1 + seen_blocks = {b for _, b in cells} + short = [f"{lbl} block {blk}: {n}/{want_runs} launches" + for (lbl, blk), n in sorted(cells.items()) if n != want_runs] + name = path if len(per_file) > 1 else "this CSV" + if len(seen_blocks) != want_blocks: + shortfalls.append(f" {name}: {len(seen_blocks)}/{want_blocks} blocks present") + if len(cells) != want_blocks * 2: + shortfalls.append(f" {name}: {len(cells)}/{want_blocks * 2} arm x block cells present") + shortfalls += [f" {name}: {x}" for x in short[:6]] + if shortfalls: + print("!" * 78) + print("!! INCOMPLETE EXPERIMENT MATRIX -- the CSV does not contain the run its") + print("!! own header describes. The harness was killed in a way that bypassed") + print("!! its exit trap (kill -9, host crash, power loss), so no RUN ABORTED") + print("!! marker was written and the file looks complete.") + for line in shortfalls[:10]: + print("!!" + line) + print("!" * 78) + if not a.allow_aborted: + raise SystemExit( + " refusing to analyse a truncated run. Re-run it.\n" + " --allow-aborted analyses it anyway, diagnostic only.") + print("[WARNING: --allow-aborted over a truncated matrix. DIAGNOSTIC ONLY.]") + + arms, blocks, by_pos = defaultdict(list), defaultdict(list), defaultdict(list) + by_block_pos, first_arm = defaultdict(list), {} + skipped_warmup = skipped_na = skipped_invalid = 0 + reader = ((path, r) for path, body in per_file for r in csv.DictReader(body)) + for path, r in reader: + # Include ONLY measured launches. Everything else -- warm-ups, and the + # liveness-probe launch -- is excluded by construction rather than by + # blacklist, so a new phase can never silently enter the analysis. + if r.get("phase") != "measure": + skipped_warmup += 1 + continue + # Belt and braces on top of the phase filter. The harness now labels a + # launch it rejected `measure_rejected`, but a CSV from an older build -- + # or one edited by hand -- can carry a failed launch as `measure`. These + # columns record the harness's own verdict, so honour it here too rather + # than trusting the phase label alone. + if (r.get("status") or "ok") != "ok" \ + or (r.get("launch_state") or "COLD") != "COLD" \ + or (r.get("foreground") or "ok") not in ("ok", "NA"): + skipped_invalid += 1 + continue + raw = r.get(a.metric) + if raw is None and a.metric == "total_ms": + raw = r.get("ms") + v = parse_ms(raw) + if v is None: + skipped_na += 1 + continue + arms[r["label"]].append(v) + blk = r["block"] if len(per_file) == 1 else f"{path}#{r['block']}" + blocks[(r["label"], blk)].append(v) + pos = r.get("pos_in_block") + if pos not in (None, "", "0"): + by_pos[pos].append(v) + by_block_pos[(blk, pos)].append(v) + if pos == "1": + first_arm[blk] = r["label"] + + if skipped_warmup: + print(f"[excluded {skipped_warmup} non-measured rows (warm-ups and liveness probes)]") + if skipped_invalid: + print(f"[WARNING: {skipped_invalid} row(s) labelled phase=measure failed the harness's" + f" own status/LaunchState/foreground checks and were EXCLUDED. A completed run" + f" should never contain these -- treat this CSV as an aborted run.]") + if skipped_na: + print(f"[WARNING: {skipped_na} launches had no {a.metric} value (NA). Investigate " + f"before trusting this run -- do not ignore.]") + + found = sorted(arms) + if a.baseline not in arms or a.treatment not in arms: + raise SystemExit(f"missing arm(s) {a.baseline!r}/{a.treatment!r}; " + f"CSV contains: {found}") + A, B = arms[a.baseline], arms[a.treatment] + for lbl, v in ((a.baseline, A), (a.treatment, B)): + if len(v) < 2: + raise SystemExit(f"arm {lbl!r} has {len(v)} usable launch(es); need >= 2.") + + print("=" * 78) + print(f"COLD START A/B -- {', '.join(a.csv)}") + _WINDOW = {"total_ms": "time to initial display (first frame)", + "displayed": "time to initial display (logcat Displayed)", + "ttfd": "time to FULLY DRAWN (reportFullyDrawn)", + "app_trace_ms": "the host app's OWN metric (APP_TRACE_REGEX) -- " + "window defined by the app, not by us"} + print(f"metric: {a.metric} -- {_WINDOW[a.metric]}") + if a.metric in ("total_ms", "displayed"): + print("note: ends at first frame. On React Native / Flutter apps much of startup") + print(" follows, so this understates any SDK cost landing after it. If the") + print(" app calls reportFullyDrawn(), also run with --metric ttfd.") + print("=" * 78) + print(f"{'arm':12s} {'n':>3s} {'mean':>8s} {'median':>8s} {'sd':>7s} " + f"{'min':>6s} {'max':>6s} {'IQR':>7s}") + print("-" * 78) + for lbl, v in ((a.baseline, A), (a.treatment, B)): + qs = st.quantiles(v, n=4) if len(v) >= 4 else [min(v), st.median(v), max(v)] + print(f"{lbl:12s} {len(v):3d} {st.mean(v):8.1f} {st.median(v):8.1f} " + f"{st.stdev(v):7.1f} {min(v):6.0f} {max(v):6.0f} {qs[2]-qs[0]:7.1f}") + + # ---- PRIMARY: paired block-level delta ------------------------------------- + bset = sorted({b for (_, b) in blocks}, key=lambda s: (len(s), s)) + deltas = [] + print("\n--- per-block deltas (the primary unit of analysis) ---") + for blk in bset: + va, vb = blocks.get((a.baseline, blk)), blocks.get((a.treatment, blk)) + if va and vb and len(va) >= 1 and len(vb) >= 1: + d = st.mean(vb) - st.mean(va) + deltas.append(d) + print(f" block {blk:>3s} n={len(va):2d}/{len(vb):<2d} " + f"baseline={st.mean(va):7.1f} treatment={st.mean(vb):7.1f} " + f"delta={d:+7.1f}") + + print("\n--- PRIMARY ENDPOINT: paired block-level delta ---") + if len(deltas) < 3: + print(f" NOT ESTIMABLE: {len(deltas)} complete block(s). A paired interval needs") + print(" >= 3 blocks (at 2 blocks t_crit(df=1) = 12.7, which cannot support any") + print(" significance claim). Re-run with more blocks, e.g. `... 4 8`.") + print(" Treat this run as diagnostic only.") + else: + k = len(deltas) + m = st.mean(deltas) + sd_b = st.stdev(deltas) + se_b = sd_b / math.sqrt(k) + tc = t_crit(k - 1) + lo, hi = m - tc * se_b, m + tc * se_b + print(f" blocks {k}") + print(f" mean of block deltas {m:+8.1f} ms ({100*m/st.mean(A):+.2f}% of baseline)") + print(f" between-block sd {sd_b:8.1f} ms (SE {se_b:.2f}, t_crit(df={k-1}) {tc})") + print(f" 95% CI [{lo:+.1f}, {hi:+.1f}] ms") + print(f" median of block deltas {st.median(deltas):+8.1f} ms " + f"(the descriptive median for this design)") + print(f" MDE at {k} blocks ~{mde(sd_b, k):.0f} ms " + f"(80% power, alpha=.05, two-sided)") + for target in (10, 25): + need = blocks_for(sd_b, target) + shown = f"~{need}" if need else "> 200 (not worth chasing at this sd)" + print(f" blocks to resolve {target:>2d} ms {shown}") + print() + if lo <= 0 <= hi: + print(" => No significant difference. Upper bound on any real") + print(f" regression is ~{hi:.0f} ms.") + else: + print(f" => Significant. Best estimate {m:+.0f} ms, plausible range " + f"[{lo:+.0f}, {hi:+.0f}] ms.") + + # ---- DIAGNOSTICS ---------------------------------------------------------- + d_mean, se, df, t = welch(A, B) + tc_u = t_crit(df) + print("\n--- [diagnostic] unpaired Welch over pooled launches ---") + print(" Anti-conservative: ignores between-block variance. Shown for contrast") + print(" with the primary endpoint above, not for reporting.") + print(f" mean delta {d_mean:+.1f} ms pooled median difference " + f"{st.median(B)-st.median(A):+.1f} ms") + print(" NB: 'pooled median difference' is median(treatment)-median(baseline) over all") + print(" launches. It is NOT a median treatment effect and must not be quoted as") + print(" one; the design's unit is the block. See the primary endpoint above.") + if df < 3: + print(f" CI suppressed: Welch df={df:.1f} < 3, interval not meaningful.") + else: + print(f" 95% CI [{d_mean-tc_u*se:+.1f}, {d_mean+tc_u*se:+.1f}] ms " + f"(df {df:.1f}, t_crit {tc_u})") + print(f" permutation p (mean) {fmt_p(perm_p(A, B, st.mean))}") + print(f" permutation p (median) {fmt_p(perm_p(A, B, st.median))}") + + # ---- order effect --------------------------------------------------------- + # PAIRED ON BLOCKS, for exactly the reason the primary endpoint is: an + # unpaired Welch over pooled position-1 vs position-2 launches commits the + # independence violation this module rejects two sections above, and can + # manufacture an order effect out of cell-level shifts. + # + # Under ABBA the per-block (2nd - 1st) delta also cancels the TREATMENT + # effect, because the arm that runs first alternates: odd blocks give + # (treatment - baseline) + order, even blocks give (baseline - treatment) + + # order. Averaged over an equal number of each, only `order` survives -- so + # the balance of first-arms is checked before the result is trusted. + print("\n--- [diagnostic] order effect (position within block), paired on blocks ---") + # Balance is counted over the SAME blocks that contribute a delta, not over + # every block in the run. A block missing one position (sparse `ttfd`, say) is + # dropped from order_deltas, so counting first-arms across all blocks could + # report a perfectly balanced run whose contributing subset is lopsided -- and + # then the uncancelled treatment effect shows up as an "order effect". + order_deltas, contributing = [], [] + for blk in bset: + v1, v2 = by_block_pos.get((blk, "1")), by_block_pos.get((blk, "2")) + if v1 and v2: + order_deltas.append(st.mean(v2) - st.mean(v1)) + contributing.append(blk) + firsts = Counter(first_arm[b] for b in contributing if b in first_arm) + + if len(by_pos) < 2 or len(bset) < 2: + print(" NOT ESTIMABLE: arm and position are confounded (needs >= 2 blocks with") + print(" counterbalanced order). With a single block, arm A is always first and") + print(" arm B always second, so any 'order effect' IS the treatment effect.") + elif len(order_deltas) < 3: + print(f" NOT ESTIMABLE: {len(order_deltas)} block(s) have both positions. A paired") + print(" interval needs >= 3, the same rule as the primary endpoint.") + elif len(firsts) != 2 or len(set(firsts.values())) != 1: + # The treatment effect only cancels out of (2nd - 1st) when each arm runs + # first equally often ACROSS THE CONTRIBUTING BLOCKS. Anything else leaves a + # fraction of it in the estimate, and the single-key case -- one arm always + # first -- is fully confounded, which is precisely when a warning would be + # least likely to be heeded. Suppress rather than print a contaminated number. + print(f" NOT ESTIMABLE: among the {len(order_deltas)} blocks with both positions,") + print(f" the first-arm counts are {dict(firsts)}.") + if len(firsts) < 2: + print(" Only one arm ever ran first there, so 'order effect' IS the treatment") + print(" effect -- they cannot be told apart.") + else: + print(" Each arm must run first equally often for the treatment effect to") + print(" cancel out of the 2nd-minus-1st deltas; here it does not.") + print(" (Usually caused by missing values dropping whole positions from some") + print(" blocks -- check the NA warning above.)") + else: + p1, p2 = by_pos.get("1", []), by_pos.get("2", []) + print(f" ran 1st n={len(p1):3d} mean={st.mean(p1):7.1f} | " + f"ran 2nd n={len(p2):3d} mean={st.mean(p2):7.1f} (descriptive)") + print(f" first-arm balance {dict(firsts)} -- treatment effect cancels") + k = len(order_deltas) + m = st.mean(order_deltas) + se = st.stdev(order_deltas) / math.sqrt(k) + tc = t_crit(k - 1) + lo, hi = m - tc * se, m + tc * se + print(f" 2nd-minus-1st = {m:+.1f} ms over {k} blocks 95% CI " + f"[{lo:+.1f}, {hi:+.1f}] (between-block sd {st.stdev(order_deltas):.1f})") + if abs(m) > 5 and not (lo <= 0 <= hi): + print(" !! Ordering moves the measurement independently of the build.") + print(" ABBA cancels this in the paired primary endpoint; it would") + print(" masquerade as a real effect under a fixed A-then-B order.") + else: + print(" no significant order effect -- counterbalancing is holding.") + + +if __name__ == "__main__": + main() diff --git a/tools/coldstart-benchmark/capture_trace.sh b/tools/coldstart-benchmark/capture_trace.sh new file mode 100755 index 0000000000..73624404d7 --- /dev/null +++ b/tools/coldstart-benchmark/capture_trace.sh @@ -0,0 +1,322 @@ +#!/usr/bin/env bash +# Unless explicitly stated otherwise all files in this repository are licensed +# under the Apache License Version 2.0. +# This product includes software developed at Datadog (https://www.datadoghq.com/). +# Copyright 2016-Present Datadog, Inc. +# Cold-start Perfetto capture with attestation + Datadog liveness proof. +# +# Fixes the two defects that made the original trace pair unusable: +# 1. trace.sh never installed anything, so there was no guarantee which APK +# was actually traced. This script installs + md5-attests the APK. +# 2. Nothing verified Datadog was running. The "with-datadog" trace had zero +# Datadog threads/slices. This script refuses to save a trace whose arm +# expectation is violated. +# +# Also adds sched_blocked_reason (I/O-wait attribution) which the original +# config omitted, and drives the app to a fixed state to reduce content-driven +# variance (the original pair differed by ~90 ExoPlayer/MediaCodec threads +# because one run played video and the other did not). +# +# Usage: ./capture_trace.sh +set -euo pipefail + +PKG="${PKG:?set PKG to your application id, e.g. PKG=com.example.app}" +COMPILE_FILTER="${COMPILE_FILTER:-speed-profile}" +# Must match the ANIMATIONS the A/B was run with. Forcing 0 unconditionally meant a +# benchmark run with ANIMATIONS=1 was traced with animations OFF -- so the trace omits +# the per-frame SDK work whose cost that benchmark included, and the two are no longer +# the same scenario, which is the one thing trace comparison requires. +ANIMATIONS="${ANIMATIONS:-0}" +# Same argument as ANIMATIONS: a trace taken online cannot explain a delta measured +# offline. Network-dependent startup content and SDK upload work differ between the +# two, so the capture has to reproduce whatever network mode the A/B ran under. +AIRPLANE="${AIRPLANE:-0}" +REMOTE_TRACE="/data/misc/perfetto-traces/dd-coldstart-$$.pftrace" +APK="${1:?usage: $0 }" +NAME="${2:?}" +EXPECT_DD="${3:?}" + +die() { echo "FATAL: $*" >&2; exit 1; } +case "$PKG" in *[!a-zA-Z0-9._]*|""|.*|*.) die "invalid application id: '$PKG'" ;; esac +case "$EXPECT_DD" in 0|1) ;; *) die "expect-datadog must be 0 or 1 (got '$EXPECT_DD')" ;; esac +case "$NAME" in */*|*..*|"") die "invalid trace name: '$NAME'" ;; esac +case "$ANIMATIONS" in 0|1) ;; *) die "ANIMATIONS must be 0 or 1 (got '$ANIMATIONS')" ;; esac +case "$AIRPLANE" in 0|1) ;; *) die "AIRPLANE must be 0 or 1 (got '$AIRPLANE')" ;; esac +[ -f "$APK" ] || die "APK not found: $APK" +log() { echo "[$(date +%H:%M:%S)] $*" >&2; } + +. "$(dirname "${BASH_SOURCE[0]}")/lib.sh" +dd_resolve_tools || exit 2 +dd_require_device || exit 2 +# Animations are not startup time, so they come off -- but put them back on the +# way out, including on Ctrl-C. Leaving a borrowed device with animations +# permanently disabled (and a trace file in /data/misc) is not acceptable. +# All three scales are read separately. Restoring all three from the window one +# rewrites the other two on any device where they differed -- which silently broke +# the restoration guarantee this comment claims. +_ORIG_ANIM_window_animation_scale="" +_ORIG_ANIM_transition_animation_scale="" +_ORIG_ANIM_animator_duration_scale="" +for _s in window_animation_scale transition_animation_scale animator_duration_scale; do + _v=$("$ADB" shell settings get global "$_s" 2>/dev/null | tr -d '\r') || true + printf -v "_ORIG_ANIM_$_s" '%s' "$_v" +done +_ORIG_WIFI=$("$ADB" shell settings get global wifi_on 2>/dev/null | tr -d '\r') || true +_ORIG_DATA=$("$ADB" shell settings get global mobile_data 2>/dev/null | tr -d '\r') || true +_ORIG_STAY=$("$ADB" shell settings get global stay_on_while_plugged_in 2>/dev/null | tr -d '\r') || true +_ORIG_TIMEOUT=$("$ADB" shell settings get system screen_off_timeout 2>/dev/null | tr -d '\r') || true +cleanup() { + local rc=$? + local _var _orig + for _s in window_animation_scale transition_animation_scale animator_duration_scale; do + _var="_ORIG_ANIM_$_s"; _orig="${!_var}" + # Unreadable restores to 1, the Android default -- better than leaving it at 0. + case "$_orig" in ''|null) _orig=1 ;; esac + "$ADB" shell settings put global "$_s" "$_orig" >/dev/null 2>&1 || true + done + case "$_ORIG_STAY" in ''|null) ;; *) "$ADB" shell settings put global stay_on_while_plugged_in "$_ORIG_STAY" >/dev/null 2>&1 || true ;; esac + case "$_ORIG_TIMEOUT" in ''|null) ;; *) "$ADB" shell settings put system screen_off_timeout "$_ORIG_TIMEOUT" >/dev/null 2>&1 || true ;; esac + case "$_ORIG_WIFI" in 0) "$ADB" shell svc wifi disable >/dev/null 2>&1 || true ;; + 1) "$ADB" shell svc wifi enable >/dev/null 2>&1 || true ;; esac + case "$_ORIG_DATA" in 0) "$ADB" shell svc data disable >/dev/null 2>&1 || true ;; + 1) "$ADB" shell svc data enable >/dev/null 2>&1 || true ;; esac + "$ADB" shell rm -f "$REMOTE_TRACE" >/dev/null 2>&1 || true + # Hand back exactly the permissions we force-granted below -- not a device-wide + # `pm reset-permissions`, which would also revoke grants for every other app on + # a borrowed device. + for _p in ${_GRANTED:-}; do + "$ADB" shell pm revoke "$PKG" "$_p" >/dev/null 2>&1 || true + done + return $rc +} +# Restore on EXIT only. `trap cleanup INT` returns to the interrupted line, so +# Ctrl-C mid-capture used to delete the on-device trace and revoke the grants and +# then carry on to pull a file that no longer exists. Exiting routes through EXIT +# once, with the right status. +trap cleanup EXIT +trap 'exit 130' INT +trap 'exit 143' TERM + +for _s in window_animation_scale transition_animation_scale animator_duration_scale; do + "$ADB" shell settings put global "$_s" "$ANIMATIONS" >/dev/null 2>&1 || true +done +[ "$ANIMATIONS" = 1 ] && log "animations ENABLED -- matching a benchmark run with ANIMATIONS=1" +dd_apply_radio_state "$AIRPLANE" || exit 2 +# Keep the screen on for the whole capture. Three settle launches plus a 20s trace +# outlast a default screen timeout, and a screen that sleeps mid-capture relocks the +# device -- which produces a trace with no rendering in it. +"$ADB" shell settings put global stay_on_while_plugged_in 3 >/dev/null 2>&1 || true +"$ADB" shell settings put system screen_off_timeout 1800000 >/dev/null 2>&1 || true + +# A locked device resumes the activity but never draws, so the trace would contain +# no rendering and `am start -W` no TotalTime. Same gate the benchmark applies. +"$ADB" shell input keyevent KEYCODE_WAKEUP >/dev/null 2>&1 || true +"$ADB" shell wm dismiss-keyguard >/dev/null 2>&1 || true +sleep 1 +dd_require_unlocked || exit 2 + +# Verify the APK actually declares PKG BEFORE uninstalling anything. The md5 +# attestation below only proves the file we pushed is the file that landed -- it +# says nothing about whether PKG names the same app, and by then the uninstall has +# already destroyed the data of whatever app did own that id. coldstart_bench.sh +# gates on this; trace capture is just as destructive and did not. +if [ "${ALLOW_UNVERIFIED_PKG:-0}" = "1" ]; then + log "WARNING: ALLOW_UNVERIFIED_PKG=1 -- the APK/package check is DISABLED." + log " 'adb uninstall $PKG' will run against whatever app owns that id." +else + [ -n "${AAPT2:-}" ] || die "aapt2 not found, so the APK's package name cannot be + verified against PKG='$PKG' before 'adb uninstall' destroys that app's data. + Fix: install Android SDK build-tools, or set AAPT2=/path/to/aapt2. + Override with ALLOW_UNVERIFIED_PKG=1 once you have checked by hand." + APK_PKG=$("$AAPT2" dump badging "$APK" 2>/dev/null \ + | awk -F"'" '/^package: name=/{print $2; exit}' || true) + [ -n "$APK_PKG" ] || die "aapt2 could not read a package name from $APK." + [ "$APK_PKG" = "$PKG" ] || die "PKG='$PKG' but the APK declares '$APK_PKG'. + Refusing to uninstall '$PKG' -- that would wipe an unrelated app's data." + log "APK declares $APK_PKG, matches PKG" +fi + +HOST_MD5=$(dd_md5 "$APK") +log "installing $(basename "$APK") md5=$HOST_MD5" +"$ADB" uninstall "$PKG" >/dev/null 2>&1 || true +"$ADB" install -r "$APK" >/dev/null || die "install failed" +REMOTE=$("$ADB" shell pm path "$PKG" | head -1 | sed 's/package://' | tr -d '\r') +DEV_MD5=$("$ADB" shell md5sum "$REMOTE" | awk '{print $1}' | tr -d '\r') +[ "$HOST_MD5" = "$DEV_MD5" ] || die "APK attestation failed host=$HOST_MD5 dev=$DEV_MD5" +log "APK attested OK" + +"$ADB" shell cmd package compile -m "$COMPILE_FILTER" -f "$PKG" >/dev/null +log "AOT compiled (-m $COMPILE_FILTER)" + +# Pre-grant every runtime permission the app declares -- the same thing +# coldstart_bench.sh does before it measures anything. +# +# WHY THIS IS ESSENTIAL HERE TOO: an app that asks for runtime permissions on +# first launch gets GrantPermissionsActivity stacked on top of it. That is a +# second activity launch inside the window, it pauses (and can stop) the app +# under trace, and on a stopped activity the framework produces no frames -- so +# the app never reaches its fully-drawn point and the trace records a scenario +# that never happened in the benchmark. A whole trace set was thrown away to +# this: the baseline arm was stopped at +1030 ms and rendered nothing for the +# rest of the capture, while both treatment arms carried a permissioncontroller +# launch mid-window. A trace has to be the same scenario the A/B measured, or +# its deltas are not comparable to the A/B's. +# +# Derived from the package manager rather than hardcoded, so it tracks any build. +_GRANTED="" +grant_runtime_permissions() { + local p n=0 perms + perms=$("$ADB" shell dumpsys package "$PKG" 2>/dev/null \ + | sed -n '/runtime permissions:/,/Components:/p' \ + | grep -oE '[a-z][a-zA-Z0-9_.]*\.permission\.[A-Z_]+' | sort -u | tr -d '\r') || true + for p in $perms; do + if "$ADB" shell pm grant "$PKG" "$p" >/dev/null 2>&1; then + n=$((n+1)); _GRANTED="$_GRANTED $p" + fi + done + log "pre-granted $n/$(printf '%s\n' "$perms" | grep -c . || true) runtime permissions" + [ "$n" -eq 0 ] && log "WARNING: granted none -- permission dialogs may contaminate this trace" + return 0 +} +grant_runtime_permissions + +# Measure the REAL user cold start: resolve the launcher activity rather than +# hardcoding a component. Apps commonly route the launcher through +# activity-aliases, so `am start -n ` may not be the path a user +# actually takes. +ACT=$("$ADB" shell cmd package resolve-activity --brief -c android.intent.category.LAUNCHER "$PKG" \ + | tail -1 | tr -d '\r') +# `resolve-activity --brief` prints the literal text "No activity found" (exit 0) +# when nothing matches, so a bare non-empty test passes it straight through to +# `am start -n "No activity found"`. Verified on a moto g(60)s / Android 12. +# Check the SHAPE instead: it must be / for the app under test. +case "$ACT" in + "$PKG"/*) ;; + *) die "could not resolve a launcher activity for $PKG (got '${ACT:-nothing}')." ;; +esac +START_ARGS=(-a android.intent.action.MAIN -c android.intent.category.LAUNCHER -n "$ACT") +log "launcher activity: $ACT" + +# settle: 3 discarded launches so dex/oat caches and any first-run migrations +# are done, then verify Datadog liveness on the settled state. +for _ in 1 2 3; do + "$ADB" shell am force-stop "$PKG"; sleep 3 + "$ADB" shell am start -W "${START_ARGS[@]}" >/dev/null 2>&1; sleep 8 +done + +PID=$("$ADB" shell pidof "$PKG" | tr -d '\r' | awk '{print $1}') +[ -n "$PID" ] || die "app not running" +DD=$("$ADB" shell "cat /proc/$PID/task/*/comm 2>/dev/null" | tr -d '\r' | grep -c '^datadog' || true) +log "datadog-* threads observed: $DD" +if [ "$EXPECT_DD" = "1" ] && [ "$DD" -eq 0 ]; then + die "expected Datadog ACTIVE, found none. Do not trace this build as 'with-datadog'." +fi +if [ "$EXPECT_DD" = "0" ] && [ "$DD" -ne 0 ]; then + die "expected Datadog ABSENT, found $DD datadog-* threads." +fi + +"$ADB" shell am force-stop "$PKG" +sleep 3 + +log "starting perfetto" +cat </dev/null || die "failed to pull trace" +[ -s "./$NAME.pftrace" ] || die "pulled trace is empty -- perfetto produced no output" + +# The app has to still be the resumed activity when the capture ends. If a +# permission dialog, a system prompt or the launcher took over, the trace +# records an app that was paused or stopped for part of the window, produced no +# frames while it was, and never reached its fully-drawn point -- none of which +# is the launch the benchmark measures. Liveness verification does not catch +# this: a stopped app still has all of its `datadog-*` threads. +case "$TOP" in + "$PKG"/*) log "app still foreground at end of capture ($TOP)" ;; + *) die "app was not foreground when the capture ended (top=${TOP:-unknown}). + Something took the foreground during the trace -- most often a runtime + permission dialog. The trace is kept at ./$NAME.pftrace for inspection, but it + is not the scenario the benchmark measures; do not compare it against one. + Re-capture." ;; +esac +log "saved ./$NAME.pftrace (md5 $(dd_md5 "./$NAME.pftrace"))" + +VERIFIER="$(dirname "$0")/verify_trace.py" +[ -f "$VERIFIER" ] || die "verifier missing: $VERIFIER" +log "post-hoc trace verification:" +# --require-foreground makes the verifier check ownership across the WHOLE window +# from the trace's own lifecycle slices. The end-of-capture dumpsys check below is +# kept, but it only sees the final state: an activity that took over and handed back +# mid-window is invisible to it and visible here. +VERIFY_ARGS=(--package "$PKG" --require-foreground) +if [ "$EXPECT_DD" = "1" ]; then VERIFY_ARGS+=(--expect-ndk) +else VERIFY_ARGS+=(--expect-absent); fi +# Resolve an interpreter that can import perfetto BEFORE judging the trace, so a +# missing dependency is never reported as a liveness failure. The trace is already +# on disk at this point and is worth keeping either way. +if ! dd_resolve_python; then + log "trace saved to ./$NAME.pftrace but NOT verified -- see the error above." + log "verify it once perfetto is installed:" + log " $VERIFIER ./$NAME.pftrace ${VERIFY_ARGS[*]}" + exit 2 +fi +# verify_trace.py distinguishes "SDK absent" (1) from "no cold start in this trace +# at all" (3). Collapsing both into one message sends you looking for a gated SDK +# when the real problem is that the launch happened outside the trace window. +set +e +"$PY" "$VERIFIER" "./$NAME.pftrace" "${VERIFY_ARGS[@]}" +_vrc=$? +set -e +case $_vrc in + 0) ;; + 3) die "the capture contains no cold start (no bindApplication slice), so it cannot + answer the question either way. The app was already running when tracing + began. Kept at ./$NAME.pftrace. Re-capture." ;; + 4) die "the app did not own the foreground for the whole capture (see above). + Part of the window was paused or stopped, so this is not the scenario the + benchmark measures. Kept at ./$NAME.pftrace for inspection. Re-capture." ;; + *) die "trace failed SDK liveness verification (arm expect=$EXPECT_DD, verifier exit $_vrc)" ;; +esac diff --git a/tools/coldstart-benchmark/coldstart_bench.sh b/tools/coldstart-benchmark/coldstart_bench.sh new file mode 100755 index 0000000000..5deebf56b0 --- /dev/null +++ b/tools/coldstart-benchmark/coldstart_bench.sh @@ -0,0 +1,582 @@ +#!/usr/bin/env bash +# Unless explicitly stated otherwise all files in this repository are licensed +# under the Apache License Version 2.0. +# This product includes software developed at Datadog (https://www.datadoghq.com/). +# Copyright 2016-Present Datadog, Inc. +# Cold-start A/B benchmark for measuring Datadog SDK cold-start impact. +# +# Improvements over the original ab.sh: +# * asserts the installed APK is the one we think it is (md5 of the APK we +# pushed vs. what the package manager reports) +# * PROVES Datadog is live/dead in each arm before measuring (logcat probe) +# * pins performance state: airplane mode, animations off, thermal snapshot +# * records Displayed= (TTID) from logcat AND am start -W TotalTime +# * captures reportFullyDrawn (TTFD) when the app emits it +# * pre-registers outlier policy: first N runs discarded, nothing else dropped +# * emits a tidy CSV with every raw sample + run index so nothing is hidden +# +# Usage: +# ./coldstart_bench.sh [RUNS] [BLOCKS] +# +set -euo pipefail + +PKG="${PKG:?set PKG to your application id, e.g. PKG=com.example.app}" +APK_A="${1:?usage: $0 [runs] [blocks]}" +APK_B="${2:?}" +RUNS="${3:-4}" # per block +BLOCKS="${4:-8}" # must be even (ABBA); >=3 needed for a paired CI +WARMUP="${WARMUP:-3}" # pre-registered: discarded, never analysed +# Play Store installs land on speed-profile. `speed` compiles everything AOT, +# which removes the class-load/verify cost the SDK contributes -- and overrides +# any Baseline Profile. Default to what real users get; `speed` is a documented +# lower-variance secondary. +COMPILE_FILTER="${COMPILE_FILTER:-speed-profile}" +AIRPLANE="${AIRPLANE:-0}" # 1 = run offline (sanity check vs online) +# Animation scales. 0 removes a large variance source, but it is NOT bias-free for +# an SDK that does per-frame work: fewer animated frames during the launch means +# fewer Choreographer callbacks for vitals / long-task tracking and fewer Session +# Replay snapshots, which understates those components. Default 0 for comparability +# with previous runs; set ANIMATIONS=1 to measure the per-frame cost honestly and +# quantify the bias. +ANIMATIONS="${ANIMATIONS:-0}" +# Optional: capture a duration the HOST APP logs itself, so its own startup metric can +# be A/B'd under this protocol instead of read by hand off a single launch. Give an ERE +# that matches the log line; the LAST number in the match is taken as milliseconds. +# APP_TRACE_REGEX='cold_launch_new total duration: [0-9]+' +APP_TRACE_REGEX="${APP_TRACE_REGEX:-}" +# Arm expectations for the Datadog liveness gate: 0 = expect absent, 1 = expect +# active. Override for an A/A run (same APK both arms, EXPECT_B=0), which +# measures the noise floor / false-positive rate of this very protocol. +EXPECT_A="${EXPECT_A:-0}" +EXPECT_B="${EXPECT_B:-1}" +LABEL_A="${LABEL_A:-A_noDD}" +LABEL_B="${LABEL_B:-B_withDD}" +TS="$(date +%Y%m%d_%H%M%S)" +OUT="results_$TS.csv" +LOG="bench_$TS.log" + +die() { echo "FATAL: $*" >&2; exit 1; } + +# A typo here used to silently disable the SDK-liveness gate (it tests for exactly +# "0"/"1"), and an unvalidated PKG could target the wrong app for `adb uninstall`. +case "$EXPECT_A$EXPECT_B" in [01][01]) ;; *) die "EXPECT_A/EXPECT_B must each be 0 or 1 (got '$EXPECT_A'/'$EXPECT_B')" ;; esac +case "$ANIMATIONS" in 0|1) ;; *) die "ANIMATIONS must be 0 or 1 (got '$ANIMATIONS')" ;; esac +# Every branch below tests AIRPLANE for exactly "1", so AIRPLANE=true would run +# ONLINE while the CSV header recorded airplane=true -- a run labelled offline +# that never was, silently uncomparable against a real offline run. +case "$AIRPLANE" in 0|1) ;; *) die "AIRPLANE must be 0 or 1 (got '$AIRPLANE')" ;; esac +# Identical labels would make ab_stats.py compare an arm against itself: every block +# delta is 0 and the null looks convincing. An A/A run uses LABEL_A=A1 LABEL_B=A2. +[ "$LABEL_A" != "$LABEL_B" ] || die "LABEL_A and LABEL_B are both '$LABEL_A'. The arms + must be distinguishable in the CSV -- for an A/A run use LABEL_A=A1 LABEL_B=A2." +case "$PKG" in *[!a-zA-Z0-9._]*|""|.*|*.) die "invalid application id: '$PKG'" ;; esac +case "$PKG" in *.*) ;; *) die "application id must be dotted, e.g. com.example.app (got '$PKG')" ;; esac +# RUNS/BLOCKS/WARMUP reach `seq` and arithmetic unchecked otherwise, so a typo +# surfaces as a bash arithmetic error a hundred lines later instead of here. +for _v in RUNS BLOCKS WARMUP; do + case "${!_v}" in ''|*[!0-9]*) die "$_v must be a non-negative integer (got '${!_v}')" ;; esac +done +[ $((BLOCKS % 2)) -eq 0 ] || die "BLOCKS must be even for ABBA counterbalancing (got $BLOCKS)" +[ "$BLOCKS" -ge 2 ] || die "BLOCKS must be >= 2 (got $BLOCKS)" +[ "$RUNS" -ge 1 ] || die "RUNS must be >= 1 (got $RUNS)" +[ -f "$APK_A" ] || die "baseline APK not found: $APK_A" +[ -f "$APK_B" ] || die "treatment APK not found: $APK_B" +# PKG with its dots escaped, for use inside the logcat EREs below. Unescaped, +# `com.example.app` is a pattern whose dots match any character, so a different +# package could have its Displayed/Fully-drawn line scraped as ours. +PKG_RE=$(printf '%s' "$PKG" | sed 's/[.]/\\./g') +log() { echo "[$(date +%H:%M:%S)] $*" | tee -a "$LOG" >&2; } + +. "$(dirname "${BASH_SOURCE[0]}")/lib.sh" +dd_resolve_tools || exit 2 +dd_require_device || exit 2 + +# Read package name + version out of each APK's manifest and refuse to run on a +# pair that is not what the protocol assumes. +# +# Two failures this catches, both destructive or invalidating: +# * PKG naming a DIFFERENT app than the APKs. Every block runs `adb uninstall +# $PKG`, so a wrong PKG wipes an unrelated app's data 16 times over. +# * arms built from different app versions. The guide makes matching +# versionCode/versionName a hard requirement -- it is what makes "the builds +# differ only by the SDK" checkable rather than asserted -- and until now +# nothing enforced it. +# aapt2 is REQUIRED for this: a missing one is a hard failure, overridable only +# with an explicit ALLOW_UNVERIFIED_PKG=1. +_apk_badging() { + # `|| true` is load-bearing: under `set -o pipefail` an aapt2 that cannot parse + # the file makes the pipeline non-zero, and `set -e` would then kill the run + # silently at the assignment below -- turning an optional preflight into a + # fatal one with no message at all. Empty output is the failure signal instead. + "$AAPT2" dump badging "$1" 2>/dev/null | awk -F"'" '/^package: name=/{print $2"\t"$4"\t"$6; exit}' || true +} +check_apk_pair() { + # MANDATORY, not advisory. This is the only thing standing between a typo in + # PKG and `adb uninstall` irreversibly wiping an unrelated app's data 16 times + # over. Skipping it because a tool is missing trades a fixable setup problem + # for an unrecoverable one, so a missing/unusable aapt2 is a hard failure. + local a b a_pkg b_pkg + if [ -z "${AAPT2:-}" ]; then + die "aapt2 not found, so the APK's package name cannot be verified against + PKG='$PKG' -- and every block runs 'adb uninstall \$PKG'. Refusing to run. + Fix: install Android SDK build-tools, or set AAPT2=/path/to/aapt2. + Override only if you have checked by hand that the APKs declare '$PKG': + aapt2 dump badging | grep '^package:' + then re-run with ALLOW_UNVERIFIED_PKG=1." + fi + a=$(_apk_badging "$APK_A"); b=$(_apk_badging "$APK_B") + if [ -z "$a" ] || [ -z "$b" ]; then + die "aapt2 could not read the package name out of one of the APKs, so it + cannot be checked against PKG='$PKG' before 'adb uninstall'. Refusing to + run. Check both files are real APKs; override with ALLOW_UNVERIFIED_PKG=1." + fi + a_pkg=${a%%$'\t'*}; b_pkg=${b%%$'\t'*} + log "baseline APK: $(printf '%s' "$a" | tr '\t' ' ')" + log "treatment APK: $(printf '%s' "$b" | tr '\t' ' ')" + [ "$a_pkg" = "$PKG" ] && [ "$b_pkg" = "$PKG" ] || die \ + "PKG='$PKG' does not match the APKs (baseline='$a_pkg' treatment='$b_pkg'). + Every block runs 'adb uninstall \$PKG'. Refusing to run rather than wipe + the wrong app's data. Set PKG to the application id the APKs declare." + if [ "$a" != "$b" ] && [ "${ALLOW_VERSION_MISMATCH:-0}" != "1" ]; then + die "the two APKs declare different versionCode/versionName. + Then the SDK is not the only variable between the arms and the delta is + not attributable to it. Rebuild both from the same commit, or set + ALLOW_VERSION_MISMATCH=1 if you know why they differ." + fi +} +if [ "${ALLOW_UNVERIFIED_PKG:-0}" = "1" ]; then + log "WARNING: ALLOW_UNVERIFIED_PKG=1 -- the APK/package preflight is DISABLED." + log " 'adb uninstall $PKG' will run against whatever app owns that id." +else + check_apk_pair +fi + +DEV_FP=$("$ADB" shell getprop ro.build.fingerprint | tr -d '\r') +DEV_MODEL=$("$ADB" shell getprop ro.product.model | tr -d '\r') +DEV_SDK=$("$ADB" shell getprop ro.build.version.sdk | tr -d '\r') +DEV_ABI=$("$ADB" shell getprop ro.product.cpu.abi | tr -d '\r') +# Emulator detection. A custom AVD or a third-party emulator can have a fingerprint +# and model with none of the usual keywords, so the qemu properties are the fallback +# that matters -- and only `ro.boot.qemu` was read, despite the comment naming +# `ro.kernel.qemu`. Both exist depending on the image, so read both, plus ro.hardware +# (goldfish/ranchu). Getting this wrong stamps emulator=0 on emulator data and +# bypasses the analyser's warning banner entirely. +IS_EMU=0 +case "$DEV_FP$DEV_MODEL" in *generic*|*emulator*|*sdk_gphone*|*goldfish*|*ranchu*) IS_EMU=1 ;; esac +for _prop in ro.kernel.qemu ro.boot.qemu; do + [ "$("$ADB" shell getprop "$_prop" 2>/dev/null | tr -d '\r')" = "1" ] && IS_EMU=1 +done +case "$("$ADB" shell getprop ro.hardware 2>/dev/null | tr -d '\r')" in + *goldfish*|*ranchu*) IS_EMU=1 ;; +esac +if [ "$IS_EMU" = 1 ]; then + log "*** EMULATOR DETECTED — results are for harness validation and structural" + log "*** attribution ONLY. Do not report these as your app's startup cost." +fi + +# Measure the REAL user cold start: the launcher intent, exactly as an icon tap +# produces it. Launching a component directly with `am start -n ` +# bypasses launcher routing / activity-alias selection, so it is not the path +# your field startup metric observes. +# +# Resolved AFTER each install, never once up front. `resolve-activity` asks the +# package manager about the INSTALLED build, so hoisting it above the first +# install made the harness unusable on a clean device (nothing to resolve, so it +# aborted before installing anything) and, worse, silently reused a component +# read off a leftover build when one happened to be installed. +ACT="" +resolve_launcher() { + local arm="$1" act + act=$("$ADB" shell cmd package resolve-activity --brief -c android.intent.category.LAUNCHER "$PKG" \ + | tail -1 | tr -d '\r') + # `resolve-activity --brief` prints the literal text "No activity found" (exit 0) + # when nothing matches, so a bare non-empty test passes it straight through to + # `am start -n "No activity found"`. Verified on a moto g(60)s / Android 12. + # Check the SHAPE instead: it must be / for the app under test. + case "$act" in + "$PKG"/*) ;; + *) die "[$arm] could not resolve a launcher activity for $PKG (got '${act:-nothing}'). + The app must declare an activity with category android.intent.category.LAUNCHER." ;; + esac + # Both arms must enter through the same component, or the two arms are not + # running the same scenario and the delta is not attributable to the SDK. + if [ -n "$ACT" ] && [ "$act" != "$ACT" ]; then + die "[$arm] resolves launcher '$act' but an earlier arm resolved '$ACT'. + The builds route their launcher differently (activity-alias?), so the arms + do not measure the same entry path. Refusing to compare them." + fi + ACT="$act" + START_ARGS=(-W -a android.intent.action.MAIN -c android.intent.category.LAUNCHER -n "$ACT") + log ">>> [$arm] launcher activity: $ACT" +} + +log "device: $DEV_MODEL (sdk $DEV_SDK) $DEV_FP" +log "network mode: $([ "$AIRPLANE" = 1 ] && echo OFFLINE/airplane || echo ONLINE)" +log "output: $OUT" + +# ---------------------------------------------------------------- device state +pin_device() { + log "pinning device state" + # AIRPLANE=1 isolates network-driven content variance; the default is ONLINE so we + # measure the real user cold start (content varies run to run, which n + ABBA absorb). + # Either way this changes the radios even if the operator had set them deliberately, + # so they are snapshotted and put back like every other setting we touch. + dd_apply_radio_state "$AIRPLANE" || exit 2 + for _s in window_animation_scale transition_animation_scale animator_duration_scale; do + "$ADB" shell settings put global "$_s" "$ANIMATIONS" >/dev/null 2>&1 || true + done + if [ "$ANIMATIONS" = 1 ]; then + log "animations ENABLED (higher variance; includes per-frame SDK cost)" + fi + "$ADB" shell input keyevent KEYCODE_WAKEUP >/dev/null 2>&1 || true + "$ADB" shell wm dismiss-keyguard >/dev/null 2>&1 || true + # Keep the screen awake for the duration. NOTE: this suppresses the lock screen, + # which is why restore_device() puts it back on exit. + "$ADB" shell settings put system screen_off_timeout 1800000 >/dev/null 2>&1 || true + "$ADB" shell settings put global stay_on_while_plugged_in 3 >/dev/null 2>&1 || true + # Reduce competing work. Android exposes no getter for either of these, so they + # cannot be snapshotted the way the `settings` values are. Record whether OUR + # call succeeded instead, and undo only that -- otherwise a device that arrived + # with fixed-performance mode already on, or bg-dexopt already disabled, would + # be left in the opposite state by a run that never chose it. + if "$ADB" shell cmd power set-fixed-performance-mode-enabled true >/dev/null 2>&1; then + _WE_SET_PERF=1 + fi + if "$ADB" shell cmd package bg-dexopt-job --disable >/dev/null 2>&1; then + _WE_SET_DEXOPT=1 + fi +} + + +# Capture the settings we are about to change so they can be put back. Without +# this the harness permanently leaves the device with no lock screen, animations +# disabled and every dangerous permission granted. +# +# All three animation scales are read, not just window_animation_scale: they are +# independent settings and restoring all three from the window one silently +# rewrites the other two on any device where they differed. +_ORIG_STAY=""; _ORIG_TIMEOUT=""; _ORIG_WIFI=""; _ORIG_DATA="" +_WE_SET_PERF=0; _WE_SET_DEXOPT=0 +_ORIG_ANIM_window_animation_scale="" +_ORIG_ANIM_transition_animation_scale="" +_ORIG_ANIM_animator_duration_scale="" +snapshot_device() { + local s v + _ORIG_STAY=$("$ADB" shell settings get global stay_on_while_plugged_in 2>/dev/null | tr -d '\r') || true + _ORIG_TIMEOUT=$("$ADB" shell settings get system screen_off_timeout 2>/dev/null | tr -d '\r') || true + _ORIG_WIFI=$("$ADB" shell settings get global wifi_on 2>/dev/null | tr -d '\r') || true + _ORIG_DATA=$("$ADB" shell settings get global mobile_data 2>/dev/null | tr -d '\r') || true + for s in window_animation_scale transition_animation_scale animator_duration_scale; do + v=$("$ADB" shell settings get global "$s" 2>/dev/null | tr -d '\r') || true + printf -v "_ORIG_ANIM_$s" '%s' "$v" + done + log "device state snapshotted (stay_on=$_ORIG_STAY timeout=$_ORIG_TIMEOUT" \ + "anim=$_ORIG_ANIM_window_animation_scale wifi=$_ORIG_WIFI data=$_ORIG_DATA)" +} + +restore_device() { + local rc=$? s var orig + echo "[$(date +%H:%M:%S)] restoring device state" >&2 + case "$_ORIG_STAY" in ''|null) ;; *) "$ADB" shell settings put global stay_on_while_plugged_in "$_ORIG_STAY" >/dev/null 2>&1 || true ;; esac + case "$_ORIG_TIMEOUT" in ''|null) ;; *) "$ADB" shell settings put system screen_off_timeout "$_ORIG_TIMEOUT" >/dev/null 2>&1 || true ;; esac + for s in window_animation_scale transition_animation_scale animator_duration_scale; do + var="_ORIG_ANIM_$s"; orig="${!var}" + # An unreadable scale restores to 1, the Android default -- better than + # leaving the device on 0 because one `settings get` came back empty. + case "$orig" in ''|null) orig=1 ;; esac + "$ADB" shell settings put global "$s" "$orig" >/dev/null 2>&1 || true + done + # Undo only what this run actually turned on (see pin_device). Still imperfect: + # with no getter we cannot tell "we enabled it" from "it was already enabled and + # our call was a no-op", so this is documented as best-effort, not a guarantee. + [ "${_WE_SET_PERF:-0}" = 1 ] && { "$ADB" shell cmd power set-fixed-performance-mode-enabled false >/dev/null 2>&1 || true; } + [ "${_WE_SET_DEXOPT:-0}" = 1 ] && { "$ADB" shell cmd package bg-dexopt-job --enable >/dev/null 2>&1 || true; } + # Radios: pin_device changes these in BOTH modes (it enables Wi-Fi in the + # default online mode), so both are restored from the snapshot rather than + # unconditionally switched back on. A setting that read back as empty or + # `null` is left alone -- we do not know what it was, and guessing is worse. + case "$_ORIG_WIFI" in 0) "$ADB" shell svc wifi disable >/dev/null 2>&1 || true ;; + 1) "$ADB" shell svc wifi enable >/dev/null 2>&1 || true ;; esac + case "$_ORIG_DATA" in 0) "$ADB" shell svc data disable >/dev/null 2>&1 || true ;; + 1) "$ADB" shell svc data enable >/dev/null 2>&1 || true ;; esac + # Hand back exactly the permissions we force-granted. NOT a device-wide + # `pm reset-permissions`: that also revokes every other app's grants, which is + # not ours to do on a borrowed or personal device. + for s in ${_GRANTED:-}; do + "$ADB" shell pm revoke "$PKG" "$s" >/dev/null 2>&1 || true + done + # Stamp an aborted run so the CSV cannot be mistaken for a complete one. It is a + # `#` line, so ab_stats.py surfaces it with the rest of the metadata. + if [ "$rc" -ne 0 ] && [ -s "$OUT" ]; then + echo "# RUN ABORTED (exit $rc) -- this CSV is a partial run, not a completed one" >> "$OUT" + fi + echo "[$(date +%H:%M:%S)] device restored. The app remains installed; 'adb uninstall $PKG' to remove." >&2 + return $rc +} +thermal_snapshot() { + { "$ADB" shell dumpsys thermalservice 2>/dev/null \ + | grep -iE "Temperature\{|mStatus" | head -6 | tr -d '\r' | tr '\n' ' '; } || true +} + +# ------------------------------------------------------- install + attestation +install_and_attest() { + local apk="$1" arm="$2" + local host_md5 + host_md5=$(dd_md5 "$apk") + log ">>> [$arm] installing $(basename "$apk") (md5 $host_md5)" + "$ADB" uninstall "$PKG" >/dev/null 2>&1 || true + "$ADB" install -r "$apk" >/dev/null || die "install failed for $apk" + + # attest: pull the installed APK back and compare digests + local remote_path dev_md5 + remote_path=$("$ADB" shell pm path "$PKG" | head -1 | sed 's/package://' | tr -d '\r') + dev_md5=$("$ADB" shell md5sum "$remote_path" | awk '{print $1}' | tr -d '\r') + if [ "$host_md5" != "$dev_md5" ]; then + die "[$arm] APK attestation FAILED: host=$host_md5 device=$dev_md5" + fi + log ">>> [$arm] APK attested OK ($remote_path)" + + log ">>> [$arm] AOT compile (-m $COMPILE_FILTER)" + "$ADB" shell cmd package compile -m "$COMPILE_FILTER" -f "$PKG" >/dev/null \ + || die "[$arm] 'cmd package compile -m $COMPILE_FILTER' failed" + # Report what the compile ACTUALLY achieved. `speed-profile` compiles only what is in + # the app's profile, and a freshly installed app has none -- so on a fresh install it + # lands at `status=verify`, i.e. NO AOT code at all, and every launch JITs the startup + # path. Silently assuming otherwise is how a run gets described as "AOT compiled" when + # it is not. Logged per arm into bench_.log; the CSV header is written before the + # first install, so it carries the requested COMPILE_FILTER, not the achieved status. + # index(), not a regex match: "[com.example.app]" as an ERE is a bracket expression and + # matches single characters, so `$0 ~ pkg` silently never fires. + DEXOPT_STATUS=$("$ADB" shell dumpsys package dexopt 2>/dev/null \ + | awk -v pkg="[$PKG]" 'index($0,pkg){found=1; next} found && /status=/{print; exit}' \ + | grep -oE 'status=[a-z-]+' | head -1 | tr -d '\r') || true + log ">>> [$arm] dexopt after compile: ${DEXOPT_STATUS:-unknown}" + # `run-from-apk` means the same thing as `verify` for our purposes -- no AOT code -- + # and it is what an emulator reports where a device reports `verify`. Warning on only + # one of them let the other pass as though the app had been compiled. + case "${DEXOPT_STATUS:-}" in + status=verify|status=run-from-apk) + log ">>> [$arm] NOTE: no AOT code (no profile to compile against on a fresh install)." + log ">>> [$arm] The startup path is JIT-compiled on every launch. This is a" + log ">>> [$arm] no-profile condition -- pessimistic vs a Play install, which" + log ">>> [$arm] ships a cloud profile. COMPILE_FILTER=speed forces full AOT." ;; + esac + grant_runtime_permissions "$arm" + resolve_launcher "$arm" +} + +# Pre-grant every runtime permission the app declares. +# +# WHY THIS IS ESSENTIAL: apps that request runtime permissions on first launch +# show the GrantPermissionsActivity dialog on top of the app. Unattended, nothing +# dismisses it, so it reappears every launch and instances accumulate (we have +# observed 23 stacked, with the dialog — not the app — as the resumed activity). +# That adds a system activity launch to every sample and drifts monotonically +# across a run. Pre-granting removes the prompt and measures the "permissions +# already decided" path, which is what returning users, and therefore your field +# startup metrics, actually reflect. +# +# Derived from the package manager rather than hardcoded, so it tracks any build. +# +# The grants are recorded in $_GRANTED so restore_device can revoke exactly +# them. Reset per call, not accumulated: each call follows a fresh install that +# already dropped the previous arm's grants, so only the last arm's survive to +# the end of the run. +_GRANTED="" +grant_runtime_permissions() { + local arm="$1" p n=0 perms + _GRANTED="" + perms=$("$ADB" shell dumpsys package "$PKG" 2>/dev/null \ + | sed -n '/runtime permissions:/,/Components:/p' \ + | grep -oE '[a-z][a-zA-Z0-9_.]*\.permission\.[A-Z_]+' | sort -u | tr -d '\r') || true + for p in $perms; do + if "$ADB" shell pm grant "$PKG" "$p" >/dev/null 2>&1; then + n=$((n+1)); _GRANTED="$_GRANTED $p" + fi + done + log ">>> [$arm] pre-granted $n/$(printf '%s\n' "$perms" | grep -c . || true) runtime permissions" + [ "$n" -eq 0 ] && log ">>> [$arm] WARNING: granted none — permission dialogs may contaminate this run" + return 0 +} + +# --------------------------------------------- prove Datadog live/dead per arm +# The Datadog Android SDK always creates a `datadog-*` thread during +# Datadog.initialize() (CoreFeature.setupExecutors + immediate NTP task submit). +# Reading /proc//task/*/comm is the cheapest reliable probe. +probe_datadog() { + local arm="$1" blk="${2:-0}" pos="${3:-0}" + "$ADB" shell am force-stop "$PKG"; sleep 3 + # This IS a real application launch and it precedes every warm-up and measured + # launch in the cell. It used to happen without leaving a CSV row, which made + # "every launch is in the CSV" untrue and made WARMUP=0 not a first launch. + # It is now recorded as phase=probe. ab_stats.py analyses phase=measure only. + local pout ptotal pstate + pout=$("$ADB" shell am start -W "${START_ARGS[@]}" 2>/dev/null | tr -d '\r') || true + ptotal=$(echo "$pout" | awk -F': *' '/^TotalTime/{print $2}') || true + pstate=$(echo "$pout" | awk -F': *' '/^LaunchState/{print $2}') || true + echo "$arm,$blk,$pos,probe,1,${ptotal:-NA},${pstate:-NA},NA,NA,NA,NA,NA,NA,NA,NA" >> "$OUT" + sleep 8 + local pid names dd + pid=$("$ADB" shell pidof "$PKG" | tr -d '\r' | awk '{print $1}') + [ -n "$pid" ] || die "[$arm] app did not start" + names=$("$ADB" shell "cat /proc/$pid/task/*/comm 2>/dev/null" | tr -d '\r' | sort -u) + dd=$(echo "$names" | grep -c '^datadog' || true) + log ">>> [$arm] threads=$(printf '%s\n' "$names" | grep -c . || true) datadog-*=$dd" + echo "$names" | grep '^datadog' | sed 's/^/ /' | tee -a "$LOG" >&2 || true + echo "$dd" +} + +# ------------------------------------------------------------------- measuring +measure() { + local arm="$1" blk="$2" phase="$3" n="$4" pos="${5:-0}" + for i in $(seq 1 "$n"); do + "$ADB" shell am force-stop "$PKG" >/dev/null 2>&1 || true + "$ADB" shell logcat -c >/dev/null 2>&1 || true + # PROVE the buffer is clear of this package's previous launch markers. `logcat -c` + # can be denied while `logcat -d` stays readable; the scrapes below take `head -1`, + # so a surviving line from an earlier launch would be recorded against THIS row and + # ab_stats.py would happily use it as the endpoint. Checking for the specific + # markers, rather than an empty buffer, tolerates ordinary system chatter. + _stale=$("$ADB" shell logcat -d 2>/dev/null | tr -d '\r' \ + | grep -cE "Displayed $PKG_RE/|Fully drawn $PKG_RE/" || true) + [ "${_stale:-0}" -eq 0 ] || die "[$arm] launch $i: 'logcat -c' left $_stale previous + launch marker(s) for $PKG in the buffer. The Displayed/Fully-drawn scrapes take + the first match, so this row would be attributed a stale timing. Clearing logcat + is likely denied on this device; fix that before measuring." + sleep 5 + local out total displayed lg dd_nat dd_rn dd_on state status ttfd fg + out=$("$ADB" shell am start "${START_ARGS[@]}" 2>/dev/null | tr -d '\r') || true + total=$(echo "$out" | awk -F': *' '/^TotalTime/{print $2}') || true + # am start -W already tells us whether this really was a cold start. Recording + # it turns "was every sample cold?" from an assumption into evidence. + state=$(echo "$out" | awk -F': *' '/^LaunchState/{print $2}') || true + status=$(echo "$out" | awk -F': *' '/^Status/{print $2}') || true + sleep 6 + lg=$("$ADB" shell logcat -d 2>/dev/null | tr -d '\r') || true + # NOTE: every extraction below MUST tolerate "no match". These strings are + # absent in the baseline build, and under `set -euo pipefail` an unguarded + # failing grep inside a command substitution aborts the whole run. + # Anchored on the AOSP format on purpose: some vendors (e.g. Motorola) log their + # own "MotoDisplayed ..." line FIRST, and an unanchored grep -m1 picks that + # one and then finds no "+NNNms", silently yielding NA on every row. + displayed=$(printf '%s\n' "$lg" \ + | grep -oE "ActivityTaskManager: Displayed $PKG_RE/[^:]*: \+[0-9smh]+" \ + | head -1 | grep -oE '\+[0-9smh]+$') || true + # TTFD, if the app calls reportFullyDrawn(). Absent for most apps. + ttfd=$(printf '%s\n' "$lg" \ + | grep -oE "Fully drawn $PKG_RE/[^:]*: \+[0-9smh]+" \ + | head -1 | grep -oE '\+[0-9smh]+$') || true + # The permission/ANR dialog contamination this guards against ACCUMULATES, so + # sampling it once per arm cannot see it. Record per launch instead. + case "$(dd_top_activity)" in "$PKG"/*) fg=ok ;; *) fg=OTHER ;; esac + # Optional: if the host app logs its own init timing, capture it. Harmless when absent. + dd_nat=$(printf '%s\n' "$lg" | grep -m1 "Datadog native initialized" \ + | grep -oE 'duration: [0-9]+' | grep -oE '[0-9]+$') || true + dd_rn=$(printf '%s\n' "$lg" | grep -m1 "Datadog RN initialized" \ + | grep -oE 'duration: [0-9]+' | grep -oE '[0-9]+$') || true + dd_on=$(printf '%s\n' "$lg" | grep -m1 "Datadog native enabled" \ + | grep -oE '(true|false)' | head -1) || true + # Host-app metric, if one was requested. Absent is not fatal: it lands as NA and + # ab_stats.py counts it in the missing-value warning rather than silently dropping it. + local app_tr="" + if [ -n "$APP_TRACE_REGEX" ]; then + app_tr=$(printf '%s\n' "$lg" | grep -m1 -oE "$APP_TRACE_REGEX" \ + | grep -oE '[0-9]+' | tail -1) || true + fi + # Decide validity BEFORE the row is written. The row used to be appended as + # phase=measure and only then checked, so a launch the harness rejected was + # already in the CSV -- and if the abort happened after >= 3 complete blocks, + # ab_stats.py would analyse the partial file and include the rejected value. + # A bad launch is still recorded (nothing is hidden), but under a phase the + # analyser excludes by construction. + local row_phase="$phase" reject="" + if [ "$phase" = measure ]; then + if [ "${status:-}" != "ok" ]; then + reject="Status='${status:-none}', not ok" + elif [ "${state:-}" != COLD ]; then + # Strict: an empty LaunchState used to be accepted here, which let a launch + # that reported nothing at all pass as cold. + reject="LaunchState='${state:-none}', not COLD. + If TotalTime was also empty, the device is almost certainly locked or the + notification shade is on top: the activity resumes but never draws, so + 'am start -W' reports nothing. Unlock the phone and re-run. + Otherwise the process was not fully reaped; increase the force-stop settle time." + elif [ "$fg" != ok ]; then + reject="ended with '$fg' in the foreground, not $PKG (dialog/crash/ANR?)" + else + # The app's own liveness marker, compared against the arm's expectation. + # Absent marker (most apps) is not a failure; a CONTRADICTING marker is. + case "${expect_dd:-}${dd_on:-}" in + 0true) reject="app reports Datadog ENABLED in the baseline arm" ;; + 1false) reject="app reports Datadog DISABLED in the treatment arm" ;; + esac + fi + [ -z "$reject" ] || row_phase="measure_rejected" + fi + echo "$arm,$blk,$pos,$row_phase,$i,${total:-NA},${state:-NA},${status:-NA},${fg:-NA},${displayed:-NA},${ttfd:-NA},${app_tr:-NA},${dd_on:-NA},${dd_nat:-NA},${dd_rn:-NA}" | tee -a "$OUT" + [ -z "$reject" ] || die "[$arm] launch $i $reject" + sleep 4 + done +} + +# ------------------------------------------------------------------------ main +snapshot_device +# Restore on EXIT only, and make INT/TERM *exit* rather than run the handler +# inline. `trap restore_device INT` returns to the interrupted loop, so Ctrl-C +# used to restore the device and then carry on benchmarking against an unpinned +# device -- every launch after the interrupt silently measured a different +# machine, and the handler ran twice. Exiting routes through the EXIT trap once. +trap restore_device EXIT +trap 'exit 130' INT +trap 'exit 143' TERM +pin_device +# pin_device wakes the screen and tries to dismiss a swipe-only keyguard; this +# catches the secure-lock case, which adb cannot dismiss. +dd_require_unlocked || exit 2 +log "thermal before: $(thermal_snapshot)" +# The header names the launcher component, which is only known after the first +# install resolves it -- so it is written once, immediately before the first row. +_HEADER_WRITTEN=0 +write_header_once() { + if [ "$_HEADER_WRITTEN" = 0 ]; then + echo "# device=$DEV_MODEL sdk=$DEV_SDK abi=$DEV_ABI emulator=$IS_EMU compile_filter=$COMPILE_FILTER blocks=$BLOCKS runs=$RUNS warmup=$WARMUP animations=$ANIMATIONS fp=$DEV_FP launcher=$ACT airplane=$AIRPLANE" > "$OUT" + echo "label,block,pos_in_block,phase,run,total_ms,launch_state,status,foreground,displayed,ttfd,app_trace_ms,dd_enabled,dd_native_init_ms,dd_rn_init_ms" >> "$OUT" + _HEADER_WRITTEN=1 + fi +} + +for b in $(seq 1 "$BLOCKS"); do + # COUNTERBALANCE the arm order (ABBA). Running A-then-B in every block turns + # any monotonic drift across the session into a systematic bias favouring A. + # An A/A validation run with fixed A-then-B order produced a spurious + # "significant" +12.7 ms (CI [+3.0,+22.5], p=0.011) on identical APKs, entirely + # from block-1 ordering. Alternating the order cancels linear drift. + if [ $((b % 2)) -eq 1 ]; then + order=("$LABEL_A:$APK_A:$EXPECT_A" "$LABEL_B:$APK_B:$EXPECT_B") + else + order=("$LABEL_B:$APK_B:$EXPECT_B" "$LABEL_A:$APK_A:$EXPECT_A") + fi + pos=0 + for arm_spec in "${order[@]}"; do + pos=$((pos+1)) + IFS=: read -r arm apk expect_dd <<<"$arm_spec" + install_and_attest "$apk" "$arm" + write_header_once + dd_count=$(probe_datadog "$arm" "$b" "$pos" | tail -1) + if [ "$expect_dd" = "1" ] && [ "$dd_count" -eq 0 ]; then + die "[$arm] expected Datadog ACTIVE but found 0 datadog-* threads. \ +Datadog did not initialize — fix before measuring (wrong APK? init gated by flag/consent?)." + fi + if [ "$expect_dd" = "0" ] && [ "$dd_count" -ne 0 ]; then + die "[$arm] expected Datadog ABSENT but found $dd_count datadog-* threads." + fi + log ">>> [$arm] warm-up x$WARMUP (pre-registered discard)" + measure "$arm" "$b" "warmup" "$WARMUP" "$pos" + log ">>> [$arm] measuring x$RUNS" + measure "$arm" "$b" "measure" "$RUNS" "$pos" + log "thermal after $arm block $b: $(thermal_snapshot)" + done +done + +log "done -> $OUT" +log "analyse with: ab_stats.py $OUT (filter phase==measure)" diff --git a/tools/coldstart-benchmark/fp_simulation.py b/tools/coldstart-benchmark/fp_simulation.py new file mode 100755 index 0000000000..2fec39bf0a --- /dev/null +++ b/tools/coldstart-benchmark/fp_simulation.py @@ -0,0 +1,110 @@ +#!/usr/bin/env python3 +# Unless explicitly stated otherwise all files in this repository are licensed +# under the Apache License Version 2.0. +# This product includes software developed at Datadog (https://www.datadoghq.com/). +# Copyright 2016-Present Datadog, Inc. +""" +Reproduces the false-positive table that justifies this harness's primary endpoint. + +The claim under test +-------------------- +`ab_stats.py` analyses one delta per BLOCK and runs a paired test on those, +rather than pooling every launch into an unpaired test. The reason is that +launches inside one arm x block cell are not independent -- they share an +install, an AOT compilation, a thermal state and a page-cache state -- so an +unpaired test estimates the standard error from WITHIN-cell scatter only and +ignores the BETWEEN-cell component. That makes it anti-conservative. + +"Anti-conservative" is easy to assert and easy to check, so this checks it. + +The model +--------- +Launch time = 0 (no true effect, by construction) + a per-cell shift drawn from +N(0, sigma_b) + per-launch noise from N(0, 11 ms). 11 ms is the pooled launch sd +from the reference A/A run. sigma_b sweeps 0, 2, 4 and 8 ms; 4 ms is an ordinary +between-block shift on a real device. + +Both designs then compute a nominal-95% interval and we count how often it +excludes zero. A correct procedure lands at 5%. + +Usage: + ./fp_simulation.py # the published table + ./fp_simulation.py --trials 50000 # tighter Monte-Carlo error +""" +import argparse +import math +import random +import statistics as st +import sys +from pathlib import Path + +sys.path.insert(0, str(Path(__file__).resolve().parent)) +from ab_stats import t_crit, welch # noqa: E402 (path set above) + +SD_WITHIN = 11.0 +SIGMA_B = (0, 2, 4, 8) + + +def _cell(n_launches, shift, rng): + return [rng.gauss(shift, SD_WITHIN) for _ in range(n_launches)] + + +def unpaired_rejects(n_blocks, n_launches, sigma_b, rng): + """Pool every launch, Welch t-interval. What most tools report.""" + a, b = [], [] + for _ in range(n_blocks): + a += _cell(n_launches, rng.gauss(0, sigma_b), rng) + b += _cell(n_launches, rng.gauss(0, sigma_b), rng) + d, se, df, _ = welch(a, b) + tc = t_crit(df) + return not (d - tc * se <= 0 <= d + tc * se) + + +def paired_rejects(n_blocks, n_launches, sigma_b, rng): + """One delta per block, paired t-interval on those. What ab_stats.py reports. + + Each ARM x BLOCK cell draws its OWN shift, matching the model: every cell gets + its own uninstall / install / AOT compile, so the thing that moves it is not + shared with the other arm in that block. Drawing one shift per block and + applying it to both arms would cancel it exactly in the delta, leaving sigma_b + with no effect at all -- the paired column would read ~5% for every sigma_b + whether or not the design actually worked, which proves nothing. + """ + deltas = [] + for _ in range(n_blocks): + deltas.append(st.mean(_cell(n_launches, rng.gauss(0, sigma_b), rng)) + - st.mean(_cell(n_launches, rng.gauss(0, sigma_b), rng))) + m = st.mean(deltas) + se = st.stdev(deltas) / math.sqrt(n_blocks) + tc = t_crit(n_blocks - 1) + return not (m - tc * se <= 0 <= m + tc * se) + + +def main(): + ap = argparse.ArgumentParser() + ap.add_argument("--trials", type=int, default=20_000) + ap.add_argument("--seed", type=int, default=7) + args = ap.parse_args() + rng = random.Random(args.seed) + + designs = ( + ("2 blocks x 15 launches, unpaired", unpaired_rejects, 2, 15), + ("8 blocks x 4 launches, paired", paired_rejects, 8, 4), + ) + # +-1 Monte-Carlo standard error on a ~5% rate, so a reader can tell a real + # difference from sampling noise without re-deriving it. + mc_se = 100 * math.sqrt(0.05 * 0.95 / args.trials) + print(f"true effect = 0, within-launch sd = {SD_WITHIN:g} ms, " + f"{args.trials} trials (MC SE at 5% ~ {mc_se:.2f}pp)") + print("false-positive rate of a nominal-95% interval\n") + print(f"{'design':36s}" + "".join(f"{f'sigma_b={s}':>12s}" for s in SIGMA_B)) + for name, fn, nb, nl in designs: + rates = [100 * sum(fn(nb, nl, s, rng) for _ in range(args.trials)) / args.trials + for s in SIGMA_B] + print(f"{name:36s}" + "".join(f"{r:11.1f}%" for r in rates)) + print("\nA correct procedure sits at 5.0% in every column. The unpaired design") + print("does not, and the gap widens with the between-block shift.") + + +if __name__ == "__main__": + main() diff --git a/tools/coldstart-benchmark/lib.sh b/tools/coldstart-benchmark/lib.sh new file mode 100755 index 0000000000..1725ebdcd8 --- /dev/null +++ b/tools/coldstart-benchmark/lib.sh @@ -0,0 +1,219 @@ +# +# Unless explicitly stated otherwise all files in this repository are licensed under the Apache License Version 2.0. +# This product includes software developed at Datadog (https://www.datadoghq.com/). +# Copyright 2016-Present Datadog, Inc. +# +# Shared helpers for the cold-start harness. Source this, don't execute it. +# +# Resolves the Android tools WITHOUT depending on the caller's PATH, so the +# harness works from cron, CI, an IDE terminal, or a shell whose profile has +# not been fixed. Precedence: +# 1. $ADB / $ANDROID_HOME / $ANDROID_SDK_ROOT if already set +# 2. PATH +# 3. well-known macOS/Linux SDK locations + +_dd_find_sdk() { + local c + for c in "${ANDROID_HOME:-}" "${ANDROID_SDK_ROOT:-}" \ + "$HOME/Library/Android/sdk" "$HOME/Android/Sdk" "$HOME/Android/sdk" \ + "/usr/local/share/android-sdk" "/opt/homebrew/share/android-sdk"; do + [ -n "$c" ] && [ -x "$c/platform-tools/adb" ] && { echo "$c"; return 0; } + done + return 1 +} + +dd_resolve_tools() { + if [ -n "${ADB:-}" ] && [ -x "${ADB}" ]; then + : + elif command -v adb >/dev/null 2>&1; then + ADB="$(command -v adb)" + else + local sdk + sdk="$(_dd_find_sdk)" || { + echo "FATAL: cannot find adb. Set ADB=/path/to/adb or ANDROID_HOME." >&2 + return 1 + } + ANDROID_HOME="$sdk" + ADB="$sdk/platform-tools/adb" + fi + + # aapt2 (optional): newest build-tools wins. Used by coldstart_bench.sh's + # preflight to read each APK's package name and version out of the manifest. + # Absent aapt2 downgrades that check to a warning rather than failing the run. + if [ -z "${AAPT2:-}" ]; then + local sdk bt + sdk="${ANDROID_HOME:-$(_dd_find_sdk 2>/dev/null || true)}" + if [ -n "$sdk" ] && [ -d "$sdk/build-tools" ]; then + # Glob + sort -V, never `ls`: `ls` output is at the mercy of the caller's + # environment. On this machine an `ls -aFh` alias makes it emit `37.0.0/` + # (and `.`/`..`), which produced a working-but-wrong `build-tools/37.0.0//aapt2`. + # Ordering must be by VERSION anyway -- lexically, "9.0.0" beats "10.0.0". + bt=$(printf '%s\n' "$sdk"/build-tools/*/ | sed 's:/*$::; s:.*/::' | sort -V | tail -1) + [ -n "$bt" ] && [ -x "$sdk/build-tools/$bt/aapt2" ] && AAPT2="$sdk/build-tools/$bt/aapt2" + fi + fi + + export ADB AAPT2 ANDROID_HOME + return 0 +} + +# Name of the currently resumed activity, as "pkg/component". +# +# The obvious `grep mResumedActivity` does NOT work everywhere: Android 12 on +# some devices (observed on a Motorola moto g60s, SDK 31) prints the record as +# `ResumedActivity:` inside the Task dump with no `m` prefix, so the anchored +# pattern matches zero lines and every foreground assertion reports OTHER. +# Match both spellings, and fall back to the window manager's focused app. +dd_top_activity() { + local top + top=$("$ADB" shell dumpsys activity activities 2>/dev/null \ + | grep -m1 -E '(^|[^a-zA-Z])m?ResumedActivity[:=]' \ + | grep -oE '[a-zA-Z0-9_.]+/[a-zA-Z0-9_.]+' | head -1 | tr -d '\r') || true + if [ -z "$top" ]; then + top=$("$ADB" shell dumpsys window 2>/dev/null \ + | grep -m1 'mFocusedApp=' \ + | grep -oE '[a-zA-Z0-9_.]+/[a-zA-Z0-9_.]+' | head -1 | tr -d '\r') || true + fi + printf '%s' "$top" +} + +# Refuse to measure behind a lockscreen. A locked device still RESUMES the +# activity -- `ResumedActivity` names the app correctly -- but no frame is ever +# drawn, so `am start -W` reports no TotalTime and LaunchState=UNKNOWN. Without +# this check the run dies later with a misleading "not fully reaped" message. +dd_require_unlocked() { + local locked focus attempt + # The notification shade and the always-on display are not locks -- they are + # just windows sitting on top, and either can be left behind by an earlier + # `input` command or by a notification arriving between runs. Clear them and + # look again before failing, otherwise an unattended sequence of captures + # loses every run after the first stray swipe. + for attempt in 1 2; do + locked=$("$ADB" shell dumpsys trust 2>/dev/null | grep -oE 'deviceLocked=[01]' | head -1 | cut -d= -f2 | tr -d '\r') || true + focus=$("$ADB" shell dumpsys window 2>/dev/null | grep -m1 mCurrentFocus | tr -d '\r') || true + case "$focus" in + *Keyguard*|*NotificationShade*|*AOD*|*DreamActivity*) locked=1 ;; + esac + { [ "${locked:-0}" = "1" ] && [ "$attempt" = 1 ]; } || break + "$ADB" shell cmd statusbar collapse >/dev/null 2>&1 || true + "$ADB" shell input keyevent KEYCODE_WAKEUP >/dev/null 2>&1 || true + "$ADB" shell wm dismiss-keyguard >/dev/null 2>&1 || true + sleep 2 + done + if [ "${locked:-0}" = "1" ]; then + echo "FATAL: the device is locked, or the lockscreen/shade is on top." >&2 + echo " A locked device still resumes the activity, but never draws a frame, so" >&2 + echo " 'am start -W' returns no TotalTime and LaunchState=UNKNOWN. Every launch" >&2 + echo " would be unmeasurable." >&2 + echo " Fix: unlock the phone by hand and leave it on the home screen. If it has a" >&2 + echo " PIN/pattern/password, adb cannot dismiss it ('wm dismiss-keyguard' only" >&2 + echo " works for a swipe-only lock)." >&2 + echo " Current focus: ${focus:-unknown}" >&2 + return 1 + fi + return 0 +} + +# A Python that can actually import `perfetto`. The trace scripts need it, and the +# usual failure is invisible: `verify_trace.py`'s shebang is `#!/usr/bin/env python3`, +# i.e. the SYSTEM interpreter, while the documented install puts `perfetto` in a +# local venv. Prefer the venv next to the scripts, then $PY, then anything on PATH +# that can import it. +dd_resolve_python() { + local here c + here="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" + for c in "${PY:-}" "$here/.venv/bin/python" "$here/.venv/bin/python3" \ + "$(command -v python3 2>/dev/null)" "$(command -v python 2>/dev/null)"; do + [ -n "$c" ] && [ -x "$c" ] || continue + if "$c" -c 'import perfetto' >/dev/null 2>&1; then PY="$c"; export PY; return 0; fi + done + echo "FATAL: no Python with the 'perfetto' package. Install it, then re-run:" >&2 + echo " python3 -m venv $here/.venv && $here/.venv/bin/pip install perfetto" >&2 + echo " (verify_trace.py's shebang is the system python3, which will not see a venv," >&2 + echo " so pass the venv interpreter explicitly when running it by hand.)" >&2 + return 1 +} + +# md5 of a local file, portable between macOS and Linux. +dd_md5() { + [ -f "$1" ] || { echo "FATAL: file not found: $1" >&2; return 1; } + if command -v md5 >/dev/null 2>&1; then md5 -q "$1" + else md5sum "$1" | awk '{print $1}'; fi +} + +# Fail unless exactly one device is attached AND authorized. Distinguishes the +# common failure modes instead of reporting a generic "no device". +dd_require_device() { + local out n_auth n_unauth n_off + out="$("$ADB" devices | tail -n +2 | grep -v '^$' || true)" + # Honour ANDROID_SERIAL, which adb itself respects: a Linux CI box or a + # workstation with an emulator running alongside a phone is a normal setup. + if [ -n "${ANDROID_SERIAL:-}" ]; then + if printf '%s\n' "$out" | grep -qE "^${ANDROID_SERIAL}[[:space:]]+device$"; then + return 0 + fi + echo "FATAL: ANDROID_SERIAL='$ANDROID_SERIAL' is not attached and authorized." >&2 + printf '%s\n' "$out" >&2 + return 1 + fi + n_auth=$(echo "$out" | grep -cE '[[:space:]]device$' || true) + n_unauth=$(echo "$out" | grep -cE '[[:space:]]unauthorized$' || true) + n_off=$(echo "$out" | grep -cE '[[:space:]]offline$' || true) + + if [ "$n_unauth" -gt 0 ]; then + echo "FATAL: device attached but UNAUTHORIZED." >&2 + echo " Unlock the phone; accept the 'Allow USB debugging?' prompt and tick" >&2 + echo " 'Always allow from this computer'. If no prompt appears:" >&2 + echo " $ADB kill-server && $ADB start-server && $ADB devices" >&2 + echo " (or revoke old keys: Developer options -> Revoke USB debugging authorisations)" >&2 + return 1 + fi + [ "$n_off" -eq 0 ] || { echo "FATAL: device is offline; replug the cable." >&2; return 1; } + if [ "$n_auth" -ne 1 ]; then + echo "FATAL: need exactly one authorized device, found $n_auth." >&2 + echo " Set ANDROID_SERIAL= to pick one." >&2 + "$ADB" devices -l >&2 + return 1 + fi + return 0 +} + +# Put the radios into the requested state and PROVE they got there. +# +# `svc` is best-effort and silently no-ops without root -- `svc data disable` needs +# root on most retail devices -- so without a read-back a run can be stamped +# airplane=1 while mobile data is still up. That is not merely noisy, it is +# mislabelled, and uncomparable against a genuinely offline run. +# +# Shared because BOTH the benchmark and the trace capture need the same network +# condition: a trace taken online cannot explain a delta measured offline. +# $1 = 1 for offline, 0 for online. Only offline is enforced; in online mode a radio +# that will not come up is reported, since the run is still "online" as labelled. +dd_apply_radio_state() { + local want="$1" + if [ "$want" = 1 ]; then + "$ADB" shell svc wifi disable >/dev/null 2>&1 || true + "$ADB" shell svc data disable >/dev/null 2>&1 || true + else + "$ADB" shell svc wifi enable >/dev/null 2>&1 || true + fi + sleep 2 + local w d + w=$("$ADB" shell settings get global wifi_on 2>/dev/null | tr -d '\r') || true + d=$("$ADB" shell settings get global mobile_data 2>/dev/null | tr -d '\r') || true + if [ "$want" = 1 ]; then + case "$w" in 1) echo "FATAL: AIRPLANE=1 but Wi-Fi is still on ('svc wifi disable' had no" >&2 + echo " effect -- it needs root on many devices). Refusing to record a run" >&2 + echo " stamped airplane=1 that was not offline. Turn Wi-Fi off by hand." >&2 + return 1 ;; esac + case "$d" in 1) echo "FATAL: AIRPLANE=1 but mobile data is still on ('svc data disable'" >&2 + echo " needs root on most retail devices). Refusing to record a run stamped" >&2 + echo " airplane=1 that was not offline. Disable it by hand." >&2 + return 1 ;; esac + echo "[radios verified OFF (wifi_on=$w mobile_data=$d)]" >&2 + else + echo "[radios: wifi_on=${w:-unknown} mobile_data=${d:-unknown}]" >&2 + case "$w" in 0) echo "[NOTE: Wi-Fi did not come up; device may be on mobile data or offline.]" >&2 ;; esac + fi + return 0 +} diff --git a/tools/coldstart-benchmark/verify_sdk_active.sh b/tools/coldstart-benchmark/verify_sdk_active.sh new file mode 100755 index 0000000000..eb9a78f15c --- /dev/null +++ b/tools/coldstart-benchmark/verify_sdk_active.sh @@ -0,0 +1,146 @@ +#!/usr/bin/env bash +# Unless explicitly stated otherwise all files in this repository are licensed +# under the Apache License Version 2.0. +# This product includes software developed at Datadog (https://www.datadoghq.com/). +# Copyright 2016-Present Datadog, Inc. +# STEP ZERO. Run this before anything else. +# +# Answers one question empirically: does this APK actually initialize the Datadog +# SDK at runtime, or not? +# +# A build that CONTAINS the SDK is not necessarily one that INITIALIZES it: feature +# flags, remote config, experiment buckets and consent gating can all leave it +# compiled in but inert. Inferring liveness from a trace is unreliable, so this +# script installs the build itself, attests it by md5, launches it via the real +# launcher intent, and reads the live thread list. +# +# Oracle: `CoreFeature.initialize()` calls `setupExecutors()` and immediately +# submits the NTP-sync task to `persistenceExecutorService` +# (dd-sdk-android-core/.../CoreFeature.kt:265-266). That executor is built with +# `DatadogThreadFactory`, which names threads `datadog--thread-` +# (Linux truncates to 15 chars -> `datadog-storage`). The name is assembled at +# runtime from a string template, so R8/ProGuard cannot rename it. A completed +# `Datadog.initialize()` therefore ALWAYS leaves a `datadog-*` thread. +# +# Usage: ./verify_sdk_active.sh +set -euo pipefail + +APK="${1:?usage: $0 }" +PKG="${2:? required}" +SETTLE="${SETTLE:-20}" # seconds to wait after launch before sampling + +die() { echo "FATAL: $*" >&2; exit 2; } +[ -f "$APK" ] || die "APK not found: $APK" +case "$PKG" in *[!a-zA-Z0-9._]*|""|.*|*.) die "invalid application id: '$PKG'" ;; esac +case "$PKG" in *.*) ;; *) die "application id must be dotted, e.g. com.example.app" ;; esac +log() { echo "[$(date +%H:%M:%S)] $*" >&2; } + +. "$(dirname "${BASH_SOURCE[0]}")/lib.sh" +dd_resolve_tools || exit 2 +dd_require_device || exit 2 + +echo "device: $("$ADB" shell getprop ro.product.model | tr -d '\r') / $("$ADB" shell getprop ro.build.fingerprint | tr -d '\r')" +echo "android: $("$ADB" shell getprop ro.build.version.release | tr -d '\r') (sdk $("$ADB" shell getprop ro.build.version.sdk | tr -d '\r'))" +echo + +# Check the APK declares BEFORE uninstalling anything. The md5 +# attestation below runs only after the install, so it cannot prevent a mistyped +# package from wiping an unrelated app first. This script is documented as step +# zero, so it is the most likely place for that typo to be made. +if [ "${ALLOW_UNVERIFIED_PKG:-0}" = "1" ]; then + log "WARNING: ALLOW_UNVERIFIED_PKG=1 -- the APK/package check is DISABLED." + log " 'adb uninstall $PKG' will run against whatever app owns that id." +else + [ -n "${AAPT2:-}" ] || die "aapt2 not found, so the APK's package name cannot be + verified against '$PKG' before 'adb uninstall' destroys that app's data. + Fix: install Android SDK build-tools, or set AAPT2=/path/to/aapt2. + Override with ALLOW_UNVERIFIED_PKG=1 once you have checked by hand." + APK_PKG=$("$AAPT2" dump badging "$APK" 2>/dev/null \ + | awk -F"'" '/^package: name=/{print $2; exit}' || true) + [ -n "$APK_PKG" ] || die "aapt2 could not read a package name from $APK." + [ "$APK_PKG" = "$PKG" ] || die "you passed package '$PKG' but the APK declares + '$APK_PKG'. Refusing to uninstall '$PKG' -- that would wipe an unrelated + app's data. Re-run with '$APK_PKG'." + log "APK declares $APK_PKG, matches the package argument" +fi + +# Say it at the point of destruction, not only in the README. This is the script an +# operator is most likely to run casually -- it is documented as "step zero" -- and it +# is just as destructive as the benchmark. +if "$ADB" shell pm path "$PKG" >/dev/null 2>&1; then + log "WARNING: $PKG is already installed. Uninstalling it now to guarantee a known" + log " install state -- THIS DELETES ITS APP DATA (accounts, caches, databases)." +fi +HOST_MD5=$(dd_md5 "$APK") +log "installing $(basename "$APK") md5=$HOST_MD5" +"$ADB" uninstall "$PKG" >/dev/null 2>&1 || true +"$ADB" install -r "$APK" >/dev/null || die "install failed (v2/v3-signed APK requires Android 7+)" + +REMOTE=$("$ADB" shell pm path "$PKG" | head -1 | sed 's/package://' | tr -d '\r') +DEV_MD5=$("$ADB" shell md5sum "$REMOTE" | awk '{print $1}' | tr -d '\r') +[ "$HOST_MD5" = "$DEV_MD5" ] \ + || die "APK attestation FAILED host=$HOST_MD5 device=$DEV_MD5 — the device is not running the APK you think it is" +log "APK attested OK ($REMOTE)" +# The grepped line already reads "versionName=..."; prefixing it again printed +# "versionName=versionName=3.13.0-SNAPSHOT". +log "$("$ADB" shell dumpsys package "$PKG" | grep -m1 versionName | tr -d '\r' | xargs)" + +# Real launcher intent, exactly as tapping the icon does. +LAUNCH=$("$ADB" shell cmd package resolve-activity --brief -c android.intent.category.LAUNCHER "$PKG" \ + | tail -1 | tr -d '\r') +# `resolve-activity --brief` prints the literal text "No activity found" (exit 0) +# when nothing matches, so a bare non-empty test passes it straight through to +# `am start -n "No activity found"`. Verified on a moto g(60)s / Android 12. +# Check the SHAPE instead: it must be / for the app under test. +case "$LAUNCH" in + "$PKG"/*) ;; + *) die "could not resolve a launcher activity for $PKG (got '${LAUNCH:-nothing}')." ;; +esac +log "launcher activity: $LAUNCH" + +"$ADB" shell am force-stop "$PKG"; sleep 2 +"$ADB" shell logcat -c >/dev/null 2>&1 || true +"$ADB" shell am start -W -a android.intent.action.MAIN -c android.intent.category.LAUNCHER -n "$LAUNCH" \ + | tr -d '\r' | sed 's/^/ /' +log "settling ${SETTLE}s so any deferred/async init completes" +sleep "$SETTLE" + +PID=$("$ADB" shell pidof "$PKG" | tr -d '\r' | awk '{print $1}') +[ -n "$PID" ] || die "app is not running after launch" + +ALL=$("$ADB" shell "cat /proc/$PID/task/*/comm 2>/dev/null" | tr -d '\r' | sort) +DD=$(echo "$ALL" | grep '^datadog' || true) +N_ALL=$(echo "$ALL" | grep -c . || true) +N_DD=$(echo "$DD" | grep -c . || true) + +echo +echo "==============================================================" +echo " threads live in pid $PID : $N_ALL" +echo " datadog-* threads : $N_DD" +# shellcheck disable=SC2001 # indenting every line of a list; parameter expansion cannot +[ -n "$DD" ] && echo "$DD" | sed 's/^/ /' +echo "--------------------------------------------------------------" +# Secondary evidence: is the NDK crash-reporting lib mapped in? +NDKMAP=$("$ADB" shell "grep -c libdatadog-ndk /proc/$PID/maps 2>/dev/null" | tr -d '\r' || echo 0) +echo " libdatadog-ndk.so mapped : ${NDKMAP:-0}" +# Tertiary: SDK's own logcat output +echo " Datadog logcat lines : $("$ADB" shell logcat -d 2>/dev/null | grep -ci datadog | tr -d '\r')" +echo "==============================================================" +echo + +if [ "$N_DD" -gt 0 ]; then + echo "RESULT: Datadog IS initializing in this build." + echo " => proceed to coldstart_bench.sh." + exit 0 +else + echo "RESULT: Datadog is NOT initializing in this build, on this device," + echo " with an attested install and a ${SETTLE}s settle window." + echo " => next: check how init is gated in the host app (remote flag / experiment /" + echo " consent / build variant), and check logcat for SDK errors:" + echo " \$ADB shell logcat -d | grep -iE 'datadog|DD_SDK'" + echo + echo " Datadog-related logcat lines captured this run:" + "$ADB" shell logcat -d --pid="$PID" 2>/dev/null | grep -iE 'datadog|DD_SDK' \ + | head -20 | sed 's/^/ /' || echo " (none)" + exit 1 +fi diff --git a/tools/coldstart-benchmark/verify_trace.py b/tools/coldstart-benchmark/verify_trace.py new file mode 100755 index 0000000000..ea113a98db --- /dev/null +++ b/tools/coldstart-benchmark/verify_trace.py @@ -0,0 +1,257 @@ +#!/usr/bin/env python3 +# Unless explicitly stated otherwise all files in this repository are licensed +# under the Apache License Version 2.0. +# This product includes software developed at Datadog (https://www.datadoghq.com/). +# Copyright 2016-Present Datadog, Inc. +""" +GUARD: assert that the Datadog Android SDK actually initialized inside a trace. + +Why this exists +--------------- +A trace labelled "with SDK" can contain no SDK activity at all — if the SDK never +initialized, every conclusion drawn from that trace attributes platform and app +noise to the SDK. Any cold-start trace must pass this check before it is analysed. + +What it looks for (in order of strength) +--------------------------------------- +1. `datadog-*` threads. STRONGEST SIGNAL. + `CoreFeature.initialize()` calls `setupExecutors()` and then immediately + submits the NTP-sync task to `persistenceExecutorService` + (dd-sdk-android-core/.../CoreFeature.kt:265-266). That executor uses + `DatadogThreadFactory`, which names threads + `datadog--thread-` (truncated by Linux to 15 chars, e.g. + `datadog-storage`). So a successful `Datadog.initialize()` ALWAYS leaves at + least one `datadog-*` thread. R8/ProGuard cannot rename these, because the + name is built at runtime from a string template. + +2. `libdatadog-ndk.so` load, when NDK crash reporting is enabled. + NOTE: Datadog uses a plain `System.loadLibrary`, which does not always emit + its own atrace slice, so absence here is suggestive but NOT conclusive. + +3. Any slice / track / arg containing "datadog". + +Exit codes +---------- +0 Datadog demonstrably active -- or correctly absent, under --expect-absent. +1 Datadog NOT active, or the package is not in the trace. Do not analyse. + Sound as a negative only because the trace contains the cold start. +3 Trace unusable: no `bindApplication`, so there is no launch in it at all. + Distinct from 1 on purpose -- it says nothing about the SDK either way. +4 With --require-foreground: something else owned the foreground during the + capture. The SDK may well be active; the trace is just not the scenario the + benchmark measured, so its deltas are not comparable to the benchmark's. + +Usage: verify_trace.py --package + [--expect-ndk] [--expect-session-replay] [--expect-absent] +""" +import argparse +import re +import sys +from perfetto.trace_processor import TraceProcessor + + +def main(): + """Own the TraceProcessor lifetime so every exit path closes it. + + `analyse()` returns from five different places; each used to need its own + tp.close(), one was missed, and an exception skipped all of them -- leaving + the trace_processor subprocess running. + """ + args = parse_args() + if not re.match(r'^[A-Za-z][A-Za-z0-9_]*(\.[A-Za-z0-9_]+)+$', args.package): + print(f"FAIL: implausible application id {args.package!r}") + return 1 + tp = TraceProcessor(trace=args.trace) + try: + return analyse(tp, args) + finally: + tp.close() + + +def parse_args(): + ap = argparse.ArgumentParser() + ap.add_argument("trace") + ap.add_argument("--package", required=True, + help="your application id, e.g. com.example.app") + ap.add_argument("--expect-ndk", action="store_true", + help="config calls NdkCrashReports.enable() / nativeCrashReportEnabled") + ap.add_argument("--expect-session-replay", action="store_true") + ap.add_argument("--expect-absent", action="store_true", + help="this is the BASELINE arm: passing means NO Datadog activity") + ap.add_argument("--require-foreground", action="store_true", + help="exit 4 unless the app owned the foreground for the whole " + "capture, not merely at the end") + return ap.parse_args() + + +def analyse(tp, args): + rows = list(tp.query( + f"select upid, pid from process where name = '{args.package}' order by pid limit 1")) + if not rows: + print(f"FAIL: process {args.package} not present in trace") + return 1 + upid, pid = rows[0].upid, rows[0].pid + + def scalar(sql): + return list(tp.query(sql))[0].c + + total_threads = scalar(f"select count(*) c from thread where upid = {upid}") + + # --- Can this trace support a NEGATIVE conclusion at all? ----------------- + # The oracle ("no datadog-* thread => init did not run") only holds if the + # trace actually enumerates threads that exist but are idle. With a bare + # `linux.process_stats` data source (no process_stats_config), Perfetto names + # threads only from ftrace sched events, so an idle thread is INVISIBLE and + # its absence proves nothing. + # Test: does any named thread have zero scheduler slices? If none do, thread + # naming is sched-derived only. + idle_named = scalar( + f"select count(*) c from thread t where t.upid = {upid} and t.name is not null " + "and not exists (select 1 from thread_state ts where ts.utid = t.utid)") + # Is there a cold start in here at all? + has_bind = scalar( + "select count(*) c from slice s join thread_track tt on s.track_id = tt.id " + f"join thread t on tt.utid = t.utid where t.upid = {upid} " + "and s.name = 'bindApplication'") + proc_started_in_trace = scalar( + f"select count(*) c from process where upid = {upid} and start_ts is not null") + dd_threads = list(tp.query( + f"select name, tid from thread where upid = {upid} and lower(name) glob 'datadog*'")) + dd_slices = scalar( + "select count(*) c from slice s join thread_track tt on s.track_id = tt.id " + f"join thread t on tt.utid = t.utid where t.upid = {upid} " + "and lower(s.name) like '%datadog%'") + ndk_load = scalar("select count(*) c from slice " + "where lower(name) like '%datadog-ndk%'") + total_jit = scalar("select count(*) c from slice where name like 'JIT compiling%'") + + print(f"=== {args.trace} ===") + print(f" package {args.package} (pid {pid})") + print(f" threads enumerated {total_threads}") + print(f" datadog-* threads {len(dd_threads)}" + + (f" -> {[(r.name, r.tid) for r in dd_threads]}" if dd_threads else "")) + print(f" slices matching datadog {dd_slices}") + print(f" libdatadog-ndk loads {ndk_load}") + print(f" (JIT slices in trace {total_jit} — confirms class-name capture works)") + + print(f" named-but-idle threads {idle_named}" + f" {'(enumerates idle threads)' if idle_named else '(sched-derived naming ONLY)'}") + print(f" bindApplication slices {has_bind}" + f" {'' if has_bind else '<- NO COLD START IN THIS TRACE'}") + print(f" process start in trace {'yes' if proc_started_in_trace else 'no (already running)'}") + + # The thread is the ONLY reliable oracle: CoreFeature.initialize() creates it + # unconditionally and R8 cannot rename it. Slices are corroborating output only -- + # OR-ing them in lets the verdict be right for the wrong reason, or simply wrong. + active = bool(dd_threads) + print() + + # Whether a NEGATIVE verdict is sound depends on where init would have run + # relative to the trace window: + # + # * Cold start IS in the trace (bindApplication present) -> CONCLUSIVE. + # `Datadog.initialize()` would run inside the window, and CoreFeature + # creates `datadog-storage-thread-1` and IMMEDIATELY submits the NTP-sync + # task to it (CoreFeature.kt:265-266). A thread that is created and runs a + # task necessarily produces sched events, so it cannot be invisible -- + # sched-derived naming is sufficient here. + # + # * No cold start (process pre-existed) -> INCONCLUSIVE when naming is + # sched-derived only. Init happened before the window; the datadog + # executors may simply have been idle and therefore unnamed. + if not has_bind: + print(" VERDICT: UNUSABLE FOR COLD-START ANALYSIS") + print(" No `bindApplication` and no activity lifecycle: the process was already") + print(" running when tracing began. There is no launch in this trace to measure.") + if not active: + print() + if idle_named == 0: + print(" Datadog liveness: INCONCLUSIVE, not negative. Thread names here come") + print(" only from ftrace sched events (zero named-but-idle threads), so an") + print(" idle `datadog-*` thread would be invisible. Absence is not evidence.") + print(" Fix: force-stop before tracing, and capture with") + print(" process_stats_config { scan_all_processes_on_start: true" + " proc_stats_poll_ms: 1000 }") + else: + print(" Datadog liveness: NEGATIVE (this trace does enumerate idle threads,") + print(" so an existing `datadog-*` thread would have been listed).") + return 3 + + if args.expect_absent: + if active: + print(" VERDICT: FAIL — baseline arm, but Datadog IS active in this trace.") + return 1 + print(" VERDICT: PASS — baseline arm, no Datadog activity (as expected).") + return 0 + + if not active: + print(" VERDICT: *** DATADOG NOT ACTIVE IN THIS TRACE ***") + print(" This trace contains the cold start (bindApplication present), so") + print(" `Datadog.initialize()` would have run inside the window. It creates") + print(" `datadog-storage-thread-1` and immediately submits the NTP-sync task to") + print(" it (CoreFeature.kt:265-266) — a created-and-running thread always emits") + print(" sched events, so it could not have been missed. Do NOT attribute any") + print(" cost to the SDK from this trace. Confirm the Datadog build is the one") + print(" installed, and that init is not gated behind a flag/consent check.") + return 1 + + # ---- did the app own the foreground for the WHOLE window? ------------------- + # Checking `dumpsys` once after the capture only sees the END state: a permission + # dialog that appears and disappears mid-window leaves the app foreground at the + # end while part of the measured window was paused, produced no frames and never + # reached the fully-drawn point. That is a different scenario from the one the + # A/B measured, and comparing their deltas is meaningless. + # + # Lifecycle slices are bound to the PROCESS that emitted them rather than matched + # by name prefix: an app whose activity classes live outside its applicationId + # namespace would defeat prefix matching. + lifecycle = list(tp.query( + "select s.name, s.ts, t.upid from slice s " + "join thread_track tt on s.track_id = tt.id " + "join thread t on tt.utid = t.utid " + "where s.name glob 'performResume:*' or s.name glob 'performPause:*' " + " or s.name glob 'performStop:*' order by s.ts")) + ours_resume = [r.ts for r in lifecycle + if r.upid == upid and r.name.startswith("performResume:")] + fg_verdict, fg_detail = "unknown", [] + if ours_resume: + t0 = min(ours_resume) + # Our own pause/stop after we resumed, or anyone else resuming after us. + # The launcher's pause/stop as we take over happens BEFORE t0, so ordering + # keeps it from being flagged. + fg_detail = [f"{r.name} (@+{(r.ts - t0) / 1e6:.0f} ms)" for r in lifecycle + if r.ts > t0 and ( + (r.upid == upid and (r.name.startswith("performPause:") + or r.name.startswith("performStop:"))) + or (r.upid != upid and r.name.startswith("performResume:")))] + fg_verdict = "lost" if fg_detail else "held" + print(f" foreground for whole capture {fg_verdict}" + + (f" -> {fg_detail[:3]}" if fg_detail else "")) + + print(" VERDICT: Datadog active.") + if args.expect_ndk and ndk_load == 0: + print(" WARN: --expect-ndk set but no libdatadog-ndk load slice seen " + "(inconclusive: System.loadLibrary may not emit a slice).") + if args.expect_session_replay: + sr = scalar("select count(*) c from slice where lower(name) like '%sessionrep%'") + print(f" session-replay slices: {sr}" + + (" WARN: expected Session Replay activity, found none." if sr == 0 else "")) + if fg_verdict == "lost": + print() + print(" *** THE APP DID NOT OWN THE FOREGROUND FOR THE WHOLE CAPTURE ***") + print(" Something took over mid-window -- most often a runtime permission") + print(" dialog. While paused the app produces no frames and never reaches its") + print(" fully-drawn point, so this trace is NOT the scenario the benchmark") + print(" measured. Do not compare its deltas against the A/B's. Re-capture.") + for d in fg_detail[:6]: + print(f" {d}") + if args.require_foreground: + return 4 + elif fg_verdict == "unknown" and args.require_foreground: + print(" NOTE: no performResume slice for this process, so foreground ownership" + " could not be established from the trace.") + return 0 + + +if __name__ == "__main__": + sys.exit(main()) From 80342af8e2262359031edc55b6fa8b5eb0b32871 Mon Sep 17 00:00:00 2001 From: Valentin Pertuisot Date: Fri, 21 Aug 2026 16:26:58 +0200 Subject: [PATCH 2/3] RUM-18135: Document how to measure the SDK's cold-start impact MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Customers ask what the SDK costs at startup. The honest answer depends on their app, their device mix and their feature set, so the useful thing to publish is not a number but a method they can run themselves — and the caveats that decide whether the number it produces means anything. docs/benchmarking_sdk_cold_start.md walks through it: build release-configured APKs, use a physical device, prove the SDK initializes, validate the protocol with an A/A run, then measure. It states what the harness measures (a process-cold, page-cache-warm start to first frame) and tabulates which controls bias the result and in which direction — most of them downward, so the figure is closer to a lower bound than a worst case. It also documents what the exercise taught us that contradicts the intuition: * TTID is the wrong endpoint on framework apps. On one React Native app first frame was under a third of startup, so a TTID-only comparison could not have seen SDK cost in the other two thirds. * Session Replay, the SDK's heaviest feature while recording, added ~9 ms at startup — inside the noise. The cost was in the core SDK. * The largest block of SDK CPU we measured, ~149 ms of JIT (~390 ms with Session Replay), turned out not to be a startup cost at all: zero of it ran before reportFullyDrawn(). Locate work relative to your endpoint before attributing it. * Traces tell you what work exists and where. They do not give a second opinion on magnitude, and tracing itself lengthened the measured window by ~7% in every arm. Linked from the root README next to the other troubleshooting guides. The existing sdk_performance.md figures are explicitly marked as predating this protocol so they are not mistaken for a comparable baseline. --- README.md | 4 + docs/benchmarking_sdk_cold_start.md | 1036 +++++++++++++++++++++++++++ 2 files changed, 1040 insertions(+) create mode 100644 docs/benchmarking_sdk_cold_start.md diff --git a/README.md b/README.md index d852a6ab47..9d34922d32 100644 --- a/README.md +++ b/README.md @@ -106,6 +106,10 @@ If you encounter any issue when using the Datadog SDK for Android and Android TV the [troubleshooting checklist][6], [common problems](docs/advanced_troubleshooting.md), or at the existing [issues](https://github.com/DataDog/dd-sdk-android/issues?q=is%3Aissue). +If you are investigating the SDK's impact on your application's startup time, the +[cold-start benchmarking guide](docs/benchmarking_sdk_cold_start.md) walks through measuring +it on your own app, with the scripts we use internally. +
Datadog cannot guarantee the Android and Android TV SDK's performance on Roku devices running with Android OS. If you encounter any issues when using the SDK for these devices, contact Datadog Support or open an issue in our GitHub project.
diff --git a/docs/benchmarking_sdk_cold_start.md b/docs/benchmarking_sdk_cold_start.md new file mode 100644 index 0000000000..26a6cc3a5e --- /dev/null +++ b/docs/benchmarking_sdk_cold_start.md @@ -0,0 +1,1036 @@ +# Measuring the SDK's cold-start impact on your own app + +The Datadog Android SDK adds measurable work to application startup. Any observability +SDK does — it initializes before your app can report anything, and that initialization +has a cost. What matters is knowing *how much*, on your app, on the devices your users +actually hold. + +This guide gives you a reproducible way to measure that yourself. We use the same +methodology and the same scripts internally; they live in +[`tools/coldstart-benchmark`](../tools/coldstart-benchmark) so you can run exactly what we +run, and inspect how every number is produced. + +**Contents** + +- [Quick start](#quick-start) +- [Prerequisites](#prerequisites) +- [What this measures — and what it does not](#what-this-measures--and-what-it-does-not) +- [Step 1 — Build APKs that represent what you ship](#step-1--build-apks-that-represent-what-you-ship) +- [Step 2 — Use a physical device, not an emulator](#step-2--use-a-physical-device-not-an-emulator) +- [Step 3 — Prove the SDK is actually running](#step-3--prove-the-sdk-is-actually-running) +- [Step 4 — Validate your protocol with an A/A run](#step-4--validate-your-protocol-with-an-aa-run) +- [Step 5 — The controls the harness applies](#step-5--the-controls-the-harness-applies) +- [Step 6 — Run the comparison](#step-6--run-the-comparison) +- [Step 7 — Interpret the result](#step-7--interpret-the-result) +- [Where the SDK's startup cost comes from](#where-the-sdks-startup-cost-comes-from) +- [If the number is high](#if-the-number-is-high) +- [Reference](#reference) + +--- + +## Quick start + +> [!WARNING] +> **All three device-touching scripts — `verify_sdk_active.sh`, `coldstart_bench.sh` and +> `capture_trace.sh` — uninstall and reinstall your app, which deletes all app data** +> — accounts, caches, databases, preferences. That includes the step-zero verifier. Use a test device or a device +> whose state you are willing to lose. It also pre-grants the app's runtime permissions and +> changes device settings (animation scales, screen timeout, stay-awake, Wi-Fi). Everything it +> changes is snapshotted first and put back on exit, including on Ctrl-C, which stops the run. +> See [What the harness changes on your device](#what-the-harness-changes-on-your-device). + +You need two release-configured APKs of the same app version, differing only by the +Datadog SDK. [Step 1](#step-1--build-apks-that-represent-what-you-ship) explains why that +matters more than anything else here. + +```bash +git clone https://github.com/DataDog/dd-sdk-android.git +cd dd-sdk-android/tools/coldstart-benchmark +export PKG=com.example.app + +# 1. Prove the SDK actually initializes. Nothing below means anything if this fails. +./verify_sdk_active.sh app-with-datadog.apk "$PKG" + +# 2. Validate the protocol: same APK in both arms, so the true delta is zero. +EXPECT_B=0 LABEL_A=A1 LABEL_B=A2 \ + ./coldstart_bench.sh app-no-datadog.apk app-no-datadog.apk +./ab_stats.py results_.csv --baseline A1 --treatment A2 + +# 3. The real comparison. +./coldstart_bench.sh app-no-datadog.apk app-with-datadog.apk +./ab_stats.py results_.csv +``` + +Each `coldstart_bench.sh` invocation prints the exact `results_.csv` filename +it wrote; pass that file to `ab_stats.py`. + +If you use a coding agent, this repository also ships a `coldstart-benchmark` skill under +`.claude/skills/` that drives the same steps in the same order. Cloning the repo is enough +to pick it up. + + +Defaults are 4 measured launches per block × 8 blocks = 32 measured launches per arm. +Budget roughly an hour per run on a mid-range device, longer for a large APK — the +uninstall / install / AOT-compile cycle at the start of each block costs more than the +launches it precedes. + +Do not skip the A/A run. It is the only thing that tells you whether to believe the A/B. + +--- + +## Prerequisites + +| requirement | notes | +|---|---| +| a `dd-sdk-android` checkout | `git clone https://github.com/DataDog/dd-sdk-android.git` — you only need `tools/coldstart-benchmark`, you do not need to build the SDK | +| `adb` | on `PATH`, or `ANDROID_HOME` / `ANDROID_SDK_ROOT` set, or `ADB=/path/to/adb`. The harness also probes the usual macOS and Linux SDK locations | +| `aapt2` | from Android SDK build-tools, or `AAPT2=/path/to/aapt2`. Required — it is what verifies the APKs declare the `PKG` the harness is about to `adb uninstall` | +| exactly one authorized device | `adb devices` must show `device`, not `unauthorized` or `offline`. With more than one attached, set `ANDROID_SERIAL=` | +| the device **unlocked**, on the home screen | a locked device still *resumes* the activity but never draws a frame, so `am start -W` returns no `TotalTime` and `LaunchState=UNKNOWN` — every launch is unmeasurable. If the phone has a PIN, pattern or password, `adb` cannot dismiss it; unlock it by hand. The harness refuses to start rather than collect nothing | +| a **physical** device | [Step 2](#step-2--use-a-physical-device-not-an-emulator). Emulator runs are stamped `emulator=1` and are for validating the harness, never for reporting | +| Python ≥ 3.8 | for `ab_stats.py` and `fp_simulation.py`. No third-party packages needed | +| the `perfetto` package | **only** for the optional trace scripts: `python3 -m venv .venv && ./.venv/bin/pip install perfetto` | +| two release-configured APKs | same app version (matching `versionCode` / `versionName`), differing only by the Datadog SDK | +| the **host machine** kept awake for the whole run | a run is ~an hour of continuous `adb`. If the host sleeps, USB is suspended, `adb` drops the device and the run aborts. On macOS the default is to sleep after 10 minutes idle *even on AC*: check with `pmset -g` and hold it off with `caffeinate -s -w `, which releases automatically when the run exits. Locking the screen is fine; sleeping is not | + +If you installed `perfetto` into a virtualenv, run the trace verifier with that +interpreter — the script's shebang is `#!/usr/bin/env python3`, which is your *system* +Python and will not see the venv: + +```bash +./.venv/bin/python verify_trace.py treatment.pftrace --package "$PKG" +``` + +--- + +## What this measures — and what it does not + +The harness measures a **process-cold, page-cache-warm start, to first frame**. Naming all +three parts matters, because each one bounds what the number means: + +- **Process-cold.** Every launch is preceded by `am force-stop`, so the app process is gone + and `am start -W` confirms `LaunchState: COLD`. A launch that is not cold aborts the run. +- **Page-cache-warm.** `am force-stop` kills the process; it does **not** evict the kernel + page cache. By the first measured launch of a block, the app's dex, oat and native + libraries are already resident. A user's genuine first launch after install or reboot + pays page-in cost that this protocol does not see — and page-in is exactly where the + SDK's *size* contribution would show up. +- **To first frame.** The endpoint is `am start -W`'s `TotalTime`, i.e. time to initial + display (TTID). For React Native, Flutter and similar frameworks, a large part of startup + happens after first frame. See + [Know what your metric actually measures](#know-what-your-metric-actually-measures). + +Every discretionary control in this harness reduces variance, and most of them bias the +measured SDK cost *downward*. That trade is deliberate and it is spelled out in +[Which controls bias the result, and in which direction](#which-controls-bias-the-result-and-in-which-direction). +Read that table before quoting a number to anyone. + +### Glossary + +| term | meaning | +|---|---| +| **arm** | one of the two builds being compared — the baseline (no SDK) and the treatment (with SDK). Named `A_noDD` / `B_withDD` in the CSV by default | +| **block** | one contiguous baseline-and-treatment pair: uninstall, install, AOT-compile, warm up, measure, for each arm in turn. One delta is computed per block, and those per-block deltas are the unit of statistical analysis | +| **ABBA / counterbalancing** | alternating which arm runs first across blocks (block 1 baseline→treatment, block 2 treatment→baseline, …) so that drift across the session cannot masquerade as a treatment effect | +| **pooled sd** | the standard deviation of launch times within an arm, combined across arms. A measure of how noisy individual launches are | +| **MDE** (minimum detectable effect) | the smallest true difference your run had a good chance of detecting. A null result from a run whose MDE is 40 ms does not tell you the SDK costs less than 40 ms — it tells you the run could not have seen it | + +--- + +## Step 1 — Build APKs that represent what you ship + +**This is the step most likely to make your numbers meaningless.** + +A debug build and a release build are different programs. Debug builds are not optimized, +not shrunk, not obfuscated, and carry tooling your users never run. Startup cost measured +on one does not translate to the Play Store build, and the difference can run in either +direction — R8 shrinking and inlining are absent, but so are some of the checks and +allocations a release build performs. + +If you take one thing from this guide: **do not benchmark a debug build and conclude +anything about your users.** + +### Build both APKs release-configured + +Both arms must be built the way you ship: + +```kotlin +android { + buildTypes { + release { + isMinifyEnabled = true // R8: shrinking + obfuscation + isShrinkResources = true + isDebuggable = false + signingConfig = signingConfigs.getByName("release") + // your production ProGuard/R8 rules + } + } +} +``` + +Then build the same variant you publish: + +```bash +./gradlew assembleRelease +``` + +### The two builds must differ only by the SDK + +Same commit, same build type, same R8 rules, same resources, same everything else. Verify +it rather than assume it: + +```bash +aapt2 dump badging app-no-datadog.apk | grep -E "^package:" +aapt2 dump badging app-with-datadog.apk | grep -E "^package:" +``` + +`versionCode` and `versionName` should match. If they don't, you're comparing two different +app versions and the SDK is not the only variable. + +`coldstart_bench.sh` runs this check for you before it touches the device, and refuses the run +on a mismatch (`ALLOW_VERSION_MISMATCH=1` overrides it if you know why they differ). The same +preflight asserts both APKs declare the application id you put in `PKG` — every block runs +`adb uninstall $PKG`, and a wrong `PKG` would wipe an unrelated app's data sixteen times over. +`capture_trace.sh` applies the package check too, before its own uninstall. + +Both checks need `aapt2`, and a missing one **aborts the run** rather than degrading to a +warning: the whole point is to stand between a typo and an irreversible `adb uninstall`, so +skipping it when a tool is absent would defeat it. Install build-tools, set `AAPT2=`, or — having +verified the package by hand with the commands above — set `ALLOW_UNVERIFIED_PKG=1`. + +### Checklist + +| requirement | why | +|---|---| +| `isMinifyEnabled = true` on both | R8 shrinking and optimization change startup cost materially, including for SDK code | +| `isDebuggable = false` on both | debuggable builds disable ART optimizations and slow class loading | +| release signing on both | debug signing can alter install and verification behaviour | +| no debug-only tooling | LeakCanary, Chucker, Stetho, Flipper and dev menus all add startup work that is not in your production build | +| same Baseline Profile in both | if you ship one, both arms must have it — a profile in one arm only invalidates the comparison | +| measure the artifact you ship | if you publish an App Bundle, extract the device-specific APK with `bundletool build-apks --connected-device`; a universal APK contains every ABI and is not what users install | +| identical `versionCode` / `versionName` | proves the builds differ only by the SDK | + +### If you want method-level attribution, add a `profileable` build + +The A/B numbers need nothing special, and neither does the phase-level trace breakdown — +atrace slices, including the `bindApplication` slice +[`verify_trace.py`](../tools/coldstart-benchmark/verify_trace.py) uses to confirm a trace +contains a cold start, are captured from a plain release build. + +What *does* require an extra manifest flag is **method-level** attribution: Perfetto's +callstack sampling and heap profiling only work on an app that is `profileable` or +`debuggable`. On a production (`user`) build, a request against a process that is neither +[returns an empty profile][perfetto-heapprofd]. So if you want to know which methods the +time is spent in, build a **separate** APK with: + +```xml + +``` + +This is release-safe and, unlike `debuggable`, does not disable optimizations — so it is the +right tool for investigation. Use your normal release build for the headline numbers, and +this one when you need to see inside them. + +[perfetto-heapprofd]: https://perfetto.dev/docs/data-sources/native-heap-profiler + +--- + +## Step 2 — Use a physical device, not an emulator + +**Emulator measurements are close to worthless for this question.** This is not a caution +to keep in mind — it's a reason to discard the result entirely. + +An emulator runs on your development machine's CPU. A modern laptop core is many times +faster than a mid-range phone core, has vastly more cache and memory bandwidth, is backed +by an SSD instead of eMMC, and never thermally throttles. The emulator also has no +big.LITTLE scheduling, so the core contention that dominates real startup simply does not +occur. + +Those differences land hardest on precisely the phases that matter here: + +| phase | why the emulator misleads | +|---|---| +| `System.loadLibrary` / `Runtime.nativeLoad` | host SSD and page cache instead of eMMC | +| dex verification and JIT | far faster CPU, different compilation target | +| disk I/O during initialization | host filesystem | +| thread contention during startup | many fast cores, no big.LITTLE | +| thermal throttling | does not exist | + +Emulator results can be wrong in either direction, and there is no correction factor that +recovers the real answer. + +**Use a physical device that resembles what your users have.** Pull your actual device +distribution from your analytics and pick a common mid- or low-end model, not the newest +flagship on the team's desk. Startup cost is most visible on constrained hardware, which is +exactly where your real users will notice it. + +The harness detects emulators, stamps `emulator=1` into the results file, and prints a +warning banner — so an emulator run can never be mistaken later for a device run. + +--- + +## Step 3 — Prove the SDK is actually running + +**Do this before measuring anything.** + +A build that *contains* the SDK is not necessarily one that *initializes* it. Feature flags, +remote configuration, experiment buckets, consent gating and deferred initialization can all +leave the SDK compiled in but inert. If that happens, your "with SDK" arm measures dex size +and nothing else — and you'll conclude the SDK is free when you simply never turned it on. + +The SDK gives you a reliable oracle. `Datadog.initialize()` creates its internal executors +and immediately submits a clock-sync task to one of them, which forces creation of a thread +named `datadog-storage-thread-1`. Linux truncates thread names to 15 characters, so it +appears as `datadog-storage`. The name is assembled at runtime, so R8/ProGuard cannot rename +it. + +**A completed `Datadog.initialize()` always leaves at least one `datadog-*` thread.** + +```bash +adb shell am force-stop +adb shell am start -W -a android.intent.action.MAIN \ + -c android.intent.category.LAUNCHER -n / +sleep 20 # let any deferred/async initialization finish +PID=$(adb shell pidof | tr -d '\r' | awk '{print $1}') +adb shell "cat /proc/$PID/task/*/comm" | grep '^datadog' +``` + +`pidof` returns several PIDs for a multi-process app, and `adb shell` output carries `\r` on +many devices — hence the `tr` and `awk`. + +Expected on a working build: + +``` +datadog-storage +datadog-upload +``` + +Empty output means the SDK never initialized. Find out why before benchmarking: + +```bash +adb shell logcat -d | grep -iE 'datadog|DD_SDK' +``` + +Or use the script, which also verifies the installed APK matches the file you think you +installed: + +```bash +tools/coldstart-benchmark/verify_sdk_active.sh app-with-datadog.apk +``` + +If you use NDK crash reporting, `libdatadog-ndk.so` appearing in `/proc//maps` is a +second signal — corroborating only, since the SDK loads it with a plain +`System.loadLibrary`, which does not always emit a trace slice. + +--- + +## Step 4 — Validate your protocol with an A/A run + +**Run the same APK in both arms before running the real comparison.** + +The true difference is zero, so whatever your protocol reports *is* its error. This gives +you three things you cannot get any other way: + +- **A smoke test on the protocol.** If A/A reports a significant difference, the protocol is + broken and any A/B result from it is meaningless. Note the asymmetry: a *failure* is + decisive, a *pass* is not. One A/A run is a single significant-or-not outcome, so it + cannot estimate a false-positive rate — even the badly broken 2×15 unpaired design in the + table below passes about three quarters of individual A/A runs. Treat a clean A/A as + necessary but not sufficient; if you want an actual rate, you need repeated independent + A/A experiments, which is what `fp_simulation.py` does in simulation. +- **Your noise floor.** The A/A confidence interval is the smallest effect you can + credibly claim to detect. +- **Your required sample size.** The between-block spread tells you how many blocks you need + for the effect size you care about. + +```bash +cd tools/coldstart-benchmark +PKG= EXPECT_B=0 LABEL_A=A1 LABEL_B=A2 \ + ./coldstart_bench.sh app-no-datadog.apk app-no-datadog.apk +./ab_stats.py results_.csv --baseline A1 --treatment A2 +``` + +`EXPECT_B=0` tells the liveness gate not to expect `datadog-*` threads in the second arm, +because both arms are the baseline APK. If you A/A the *treatment* APK instead, use +`EXPECT_A=1 EXPECT_B=1`. + +**Pass criteria:** + +- the 95% CI on the paired block delta straddles zero +- the reported order effect is not significant +- the interval is **tight enough to be useful** — compare the printed MDE against the + effect you intend to detect in the A/B. A null from a ±100 ms interval means the + protocol cannot see anything, not that it is clean + +**Do not require the per-block deltas to share a sign.** The true delta here is zero, so +they *should* fall either side of it. Across eight null blocks unanimity happens under +1% of the time, so demanding it would reject ~99% of healthy runs — and it selects for +precisely the persistent directional bias an A/A exists to detect. Judge the spread by +the interval and the MDE, never by counting signs. + +If it fails, fix the protocol before proceeding. In our reference run, reaching a clean A/A +dropped the pooled standard deviation from 18.9 ms to 11.7 ms — a 38% reduction in sd, which +is a 62% reduction in variance. + +--- + +## Step 5 — The controls the harness applies + +Each fixes a specific, measured failure mode. The scripts apply all of them; the snippets +here are so you can see what is being done and reproduce it by hand if you need to. + +### Counterbalance the arm order (ABBA) + +If arm A always runs before arm B, any drift across the session — page cache, background +dexopt, charging behaviour, thermals — becomes a fake treatment effect. This produced the +`p = 0.011` false positive shown in +[Why the methodology is this careful](#why-the-methodology-is-this-careful); the entire +"effect" was position, not build. + +Odd-numbered blocks run baseline→treatment, even-numbered blocks treatment→baseline. Each +launch's position within its block is recorded, so `ab_stats.py` can test for an order +effect explicitly rather than assume it away. + +That test is itself **paired on blocks**, for the same reason the primary endpoint is: pooling +every position-1 launch against every position-2 launch would commit the independence violation +described in the next section and could manufacture an order effect out of cell-level shifts. +One `2nd − 1st` delta is computed per block. Because ABBA alternates which arm runs first, the +treatment effect cancels out of those deltas and only the ordering term survives — provided the +first-arm counts are balanced, which `ab_stats.py` checks and warns about if they are not. + +### Analyse per-block deltas, not pooled launches + +Launches within one arm×block cell are not independent of each other. They share an install, +an AOT compilation, a thermal state and a page-cache state. Anything that shifts a whole +cell is a cell-level random effect, and an unpaired test over pooled launches estimates its +standard error from *within-cell* scatter only — so it understates the real uncertainty. +Counterbalancing removes the ordering *bias*; it does nothing about this. + +Measured by simulation (true effect zero, within-launch sd 11 ms, per-cell shift sd σ_b), +false-positive rate of a nominal-95% interval: + +| design | σ_b = 0 | σ_b = 2 | σ_b = 4 | σ_b = 8 | +|---|---|---|---|---| +| 2 blocks × 15 launches, unpaired | 4.8% | 10.0% | **23.4%** | **45.5%** | +| 8 blocks × 4 launches, paired on block deltas | 4.8% | 4.9% | **5.0%** | 4.8% | + +Reproduce it — it calls the same interval code `ab_stats.py` uses, so the table cannot drift +away from the tool: + +```bash +./fp_simulation.py # ~20 s; --trials 50000 for tighter Monte-Carlo error +``` + +A 4 ms between-block shift is entirely ordinary, and at that level the unpaired design calls +a nonexistent effect significant nearly a quarter of the time. So `ab_stats.py` computes one +delta per block and runs a paired test on those; the unpaired Welch result is still printed, +labelled `[diagnostic]`, because it is what most tools report and the contrast is +informative. + +The practical consequence: **blocks buy statistical power, launches per block buy less of +it.** The confidence interval narrows with the square root of the number of blocks. If a run +is underpowered, add blocks before adding launches. At least 3 blocks are required for an +interval at all — below that, `ab_stats.py` refuses to produce one rather than print a +number no one should use. + +### Pre-grant runtime permissions + +If your app requests runtime permissions on first launch, an unattended benchmark never +dismisses the dialog. It reappears every launch and the instances **accumulate** — we +observed 23 stacked `GrantPermissionsActivity` instances, with the dialog rather than the app +as the resumed activity. + +Cost of leaving it unhandled: ~23 ms of absolute time, and most of the 18.9 → 11.7 ms drop +in pooled sd reported in Step 4. In the A/A table above, counterbalancing alone barely +narrowed the interval; pre-granting is what narrowed it. + +```bash +for p in $(adb shell dumpsys package \ + | sed -n '/runtime permissions:/,/Components:/p' \ + | grep -oE '[a-z][a-zA-Z0-9_.]*\.permission\.[A-Z_]+' | sort -u); do + adb shell pm grant "$p" 2>/dev/null +done +``` + +This measures the "permissions already decided" path, which is what returning users +experience and therefore what your field metrics mostly reflect. It is not the first-install +path. + +### Assert your app is in the foreground + +Verify the resumed activity is yours after every launch, not once per arm — dialog +contamination accumulates, so a single check at the start of a block cannot see it. This +catches crashes, ANR dialogs and system prompts as well. + +```bash +adb shell dumpsys activity activities | grep -m1 -E 'm?ResumedActivity[:=]' +``` + +Match both spellings. Some devices print `mResumedActivity`, others (Android 12 on a +Motorola moto g60s, for one) print `ResumedActivity:` inside the Task dump with no `m` +prefix — an anchored `grep mResumedActivity` matches nothing there and every foreground +assertion silently reports a failure. + +### Confirm each launch really was cold + +`am start -W` reports `LaunchState` and `Status`. The harness records both and aborts the run +if a measured launch comes back as anything other than `COLD` with `Status: ok`, rather than +averaging a warm launch into the result. + +### Disable animations — but know what that costs you + +```bash +for s in window_animation_scale transition_animation_scale animator_duration_scale; do + adb shell settings put global $s 0 +done +``` + +Animation time is not startup time, and animation variance is large. But this is **not a +bias-free control if the SDK does per-frame work**, which this one does: RUM vitals and +long-task tracking register `Choreographer` callbacks, and Session Replay snapshots on view +changes. Fewer animated frames in the launch window means fewer of those callbacks fire, which +understates their contribution. + +The harness defaults to animations off for low variance and comparability. `ANIMATIONS=1` runs +with them on, and the value is stamped into the CSV header so the two are never confused. If +per-frame cost matters for your app, run both and compare — that difference *is* the bias. + +**Measured, and it did not go the way we expected.** On the app above (same comparison, 32 +launches per arm each way): + +| | animations off | animations on | +|---|---|---| +| baseline TTID | 630 ms | 680 ms | +| baseline TTFD | 2074 ms | 2265 ms | +| SDK delta, TTID | +33.6 ms | +31.7 ms — unchanged, CI on the change [−15.4, +11.6] | +| SDK delta, TTFD | +88.6 ms | +40.2 ms — **smaller**, CI on the change [−80.0, −16.7] | + +TTID was unaffected. On TTFD the delta more than halved with animations *on*. The likely reason +is the opposite of the per-frame concern: animations add ~190 ms of wall-clock to startup, and +the SDK's asynchronous initialization overlaps that slack instead of extending the total. So on +this app, animations-off is the **conservative** setting — it reports the larger SDK cost. + +Do not assume this generalises. The point is that it is measurable, and that "animations off" +is a choice you should be able to defend rather than a default you inherited. + +Note that Choreographer callbacks execute on the **main thread** and emit no atrace slices, so +a Perfetto trace cannot bound this for you; only the A/B can. + +### Force AOT compilation and discard warm-ups + +A freshly installed app has no AOT profile, so early launches are slow and variable: + +```bash +adb shell cmd package compile -m speed-profile -f +``` + +`speed-profile` is what a Play Store install *converges to* over time, which is why it is the +default. **Be clear about what it does on a fresh install, though: nothing.** `speed-profile` +compiles only the methods in the app's profile, and a newly installed app has no profile — so +the app lands at `status=verify`, with no AOT code, and the startup path is JIT-compiled on +every launch. + +Check what you actually got rather than assuming: + +```bash +adb shell dumpsys package dexopt | grep -A3 "\[\]" +# arm64: [status=verify] [reason=cmdline] <- no AOT +# arm64: [status=speed] [reason=cmdline] <- fully AOT compiled +``` + +The harness logs this per arm and warns when it sees `verify`. A `verify` run is a legitimate +condition — it is what a sideloaded or freshly updated install looks like — but it is **not** +what a long-installed Play user experiences, because Play ships a cloud profile and +`bg-dexopt` recompiles against accumulated local profile data. If you want the well-compiled +end of the range, run `COMPILE_FILTER=speed` as a second arm; that forces full AOT, removes +most of the class-load and verify cost the SDK contributes, and overrides any Baseline Profile +you ship. + +Note the harness also disables `bg-dexopt-job` for the duration, so whatever state the compile +leaves is pinned for the whole run rather than drifting between blocks. + +Three warm-up launches per block are discarded. That count is fixed in advance and nothing +else is ever dropped — post-hoc outlier removal is how a null result becomes a "finding". +Warm-ups are written to the CSV and marked `phase=warmup`, so you can see what was excluded +rather than take it on trust. + +### Use the real launcher intent + +`am start -n ` is not what tapping the icon does — apps commonly route the +launcher through activity aliases: + +```bash +ACT=$(adb shell cmd package resolve-activity --brief \ + -c android.intent.category.LAUNCHER | tail -1 | tr -d '\r') +adb shell am start -W -a android.intent.action.MAIN \ + -c android.intent.category.LAUNCHER -n "$ACT" +``` + +### Verify the APK on the device is the APK you built + +```bash +adb install -r app.apk +REMOTE=$(adb shell pm path | head -1 | sed 's/package://' | tr -d '\r') +adb shell md5sum "$REMOTE" # must match md5 of your local file +``` + +### Pin the device state + +```bash +adb shell settings put global window_animation_scale 0 +adb shell settings put global transition_animation_scale 0 +adb shell settings put global animator_duration_scale 0 +adb shell settings put global stay_on_while_plugged_in 3 +``` + +The harness snapshots these first and restores them on exit, including on Ctrl-C. See +[What the harness changes on your device](#what-the-harness-changes-on-your-device), and +[Disable animations](#disable-animations--but-know-what-that-costs-you) for why the animation +scales are not a neutral choice. + +Note that `dumpsys thermalservice` returns **stubbed, non-live values on some devices** — we +have seen five consecutive byte-identical snapshots. A flat temperature reading is not +evidence that nothing drifted. + +--- + +## Step 6 — Run the comparison + +```bash +cd tools/coldstart-benchmark +PKG= ./coldstart_bench.sh app-no-datadog.apk app-with-datadog.apk +./ab_stats.py results_.csv +``` + +The defaults are 4 measured launches per block across 8 blocks. To change them, pass them +positionally — `./coldstart_bench.sh +`. `blocks` must be even, for ABBA. + +The script refuses to proceed if the "with SDK" arm shows no `datadog-*` threads, or if the +baseline arm unexpectedly shows some. + +**Give heavy features their own arm.** Run a third arm with Session Replay disabled, so you +can attribute cost to the feature that carries it and make an informed trade rather than a +blanket one. + +Do not assume in advance which way that will come out. Session Replay is the SDK's most +expensive feature *while a session is recording*, but that is not the same as being expensive +at **startup**. Measured on a React Native app on a mid-range device (8×4 design, 32 launches +per arm), enabling it added `+8.9 ms` to TTID (95% CI `[−3.2, +21.0]`) and `+10.0 ms` to TTFD +(95% CI `[−20.7, +40.6]`) — not separable from zero — against a core-SDK cost of `+24.7 ms` +and `+78.7 ms` on the same app. Startup cost there was dominated by the core SDK, not by +Session Replay. Your app may differ; the point is that this is a question to measure, not to +assume. + +--- + +## Step 7 — Interpret the result + +`ab_stats.py` reports all of the below. + +**The paired block-level delta is the primary result.** The unpaired Welch figures are +printed as a diagnostic, and are anti-conservative — see +[Analyse per-block deltas, not pooled launches](#analyse-per-block-deltas-not-pooled-launches). +Report the primary endpoint. + +**Quote a confidence interval, never a bare average.** "+11 ms" and "+11 ms, 95% CI +[−5, +27]" support completely different conclusions. If the interval includes zero, you have +not demonstrated a regression — and the interval's upper bound is your defensible upper bound +on the cost. + +**Report mean *and* median.** If they disagree materially the distribution is skewed and +neither should be quoted alone. One real dataset gave a mean delta of +8 ms and a median +delta of +40 ms — the choice of statistic changed the headline fivefold. + +**Check your minimum detectable effect before believing a null result.** "No significant +impact" from an under-powered run means "we couldn't have detected it either way". +`ab_stats.py` prints your MDE and the number of blocks needed to resolve 10 ms and 25 ms, +computed from your own between-block spread. + +Do not transplant a required-n from this guide. The script's figure is in **blocks** and is +derived from your run's own between-block spread, which is a different quantity from the +pooled launch sd — and both vary enormously with the app and the device. Our well-controlled +reference run had a pooled sd of 11.7 ms. A separate, uncontrolled run with 4 launches per arm +on a heavier app had a pooled sd near 66 ms and a 95% CI of **[−106, +122] ms** — that +protocol could not distinguish zero overhead from 120 ms of overhead. Both are real numbers +from real runs; the difference is the protocol and the app. Read the required-n the script +computes for *your* run. + +**Look at the per-block deltas, but read them against the interval, not by sign.** Blocks +falling either side of zero is normal whenever the effect is comparable to the between-block +sd, and says nothing on its own — the CI and the MDE already quantify it. What a scan of the +deltas *is* good for is spotting a single contaminated cell, which the next point covers. + +**Expect the occasional bad block, and let the design absorb it.** In one run, two of a block's +four treatment launches came in ~150 ms above that block's median while the other seven blocks +were tight. Something ran on the device during that cell. Because the primary endpoint is +paired on blocks, the contaminated cell inflated the between-block sd and widened the interval +(MDE ~62 ms against ~27 ms for comparable runs) instead of shifting the point estimate — the +unpaired Welch diagnostic on the same data reported a visibly tighter interval, which is +exactly the anti-conservatism the paired endpoint exists to avoid. Report the widened interval; +do **not** drop the block. + +**Read the bias table before quoting the number.** See +[Which controls bias the result, and in which direction](#which-controls-bias-the-result-and-in-which-direction). +The figure this harness produces is closer to a lower bound than to a worst case. + +**Put the result in context.** A cold-start delta is worth weighing against what the SDK +gives you — crash reporting, RUM and traces. A number measured properly lets you make that +trade deliberately, and lets you tune it: disabling a feature you don't need, or sampling it, +moves the number. + +--- + +## Where the SDK's startup cost comes from + +So your measurements make sense, here is what contributes — and what you can do about each: + +- **APK and dex size.** More dex means more class loading and verification at startup, + independent of initialization. R8 shrinking reduces this, which is part of why Step 1 + matters. Note that this harness measures page-cache-warm launches, so it sees the + class-load and verify cost but very little of the page-in cost. +- **A `ContentProvider` that runs before `Application.onCreate`.** `DdRumContentProvider` is + registered by the SDK to capture app-start time accurately, and runs whether or not you + call `Datadog.initialize()`. A build with the dependency but initialization disabled is + therefore not a zero-cost build. +- **A small amount of main-thread disk I/O during initialization** — storage directory + resolution, and for NDK crash reporting a directory creation plus a `System.loadLibrary`. + Clock synchronization is deliberately offloaded to a background executor. +- **Executor creation.** Initialization creates the SDK's thread pools. On devices with few + fast cores this competes with your app's own startup work. +- **JIT compilation of SDK classes on an install with no AOT profile** — the largest block of + SDK CPU we have measured, and **not** a startup cost on the app we measured it on. Across ten + traces of one React Native app: ~149 ms of JIT on `com.datadog.*` classes with Session Replay + off and ~390 ms with it on, against 0 ms in the baseline build. Then we timestamped it: + **zero** of those compilations began before `reportFullyDrawn()`, the first started 406–500 ms + *after* it, in all ten traces. It is post-launch background CPU. It costs nothing on TTID or + TTFD, and a Baseline Profile covering the SDK's init path would not have moved either number + on that app. It is still real work worth reducing — it competes with whatever your app does + after launch — but do not put it in a startup budget. This is the clearest example in this + guide of why [locating work relative to your + endpoint](#four-things-that-will-mislead-you) has to come before attributing it. +- **Per-frame callbacks** if you enable vitals or long-task tracking. +- **Session Replay.** The SDK's most expensive feature during a recording session, though on + one measured React Native app its *startup* increment was ~9 ms and not distinguishable + from zero. Give it its own arm rather than folding it into a headline "SDK on / SDK off" + number, and let the measurement decide. + +Worth knowing where this work does *not* land: in traces of the app above, there were **zero +Datadog-named slices on the main thread** in either arm. The SDK's cost showed up as background +thread CPU and as JIT contention, not as blocking main-thread work. That is why the app's own +reported initialization durations were ~10x the measured end-to-end delta — most of it runs +concurrently. It also means a Perfetto trace will not show you a neat main-thread block to +point at. + +Most of these scale with the feature set you enable, which is the main lever you have. + +If you're on React Native, also check whether the SDK is being initialized **twice** — once +natively in `Application.onCreate` and again from JavaScript. The core guards against +re-initialization, but the JS entry point still rebuilds its configuration and registers +frame callbacks. + +--- + +## If the number is high + +Work down this list before escalating. Most of it you can act on without us, and each step +either fixes the number or tells you something specific about where it comes from. + +1. **Re-read Steps 1 and 2.** A debug build or an emulator run explains most surprising + numbers, and no amount of statistics rescues either. +2. **Check the A/A result.** If your A/A run does not straddle zero, the A/B number is + measuring your protocol, not the SDK. Fix that first. +3. **Check the MDE.** A large point estimate with a CI that spans zero means the run is + underpowered, not that the effect is real. Add blocks and re-run before drawing a + conclusion. (Per-block deltas falling either side of zero is not itself a warning sign — + see [Step 7](#step-7--interpret-the-result).) +4. **Split Session Replay into its own arm.** Cheap to test and it removes a large unknown. + Note that its startup increment can be small even at `replaySampleRate: 100` — on one + measured app it was ~9 ms, well inside the noise — so if disabling it does not move your + number, the cost is in the core SDK and the next step is a per-feature breakdown. +5. **Turn features off one at a time.** Vitals and long-task tracking add per-frame + callbacks; NDK crash reporting adds a `System.loadLibrary` and a directory creation. A + per-feature breakdown turns one unusable number into a set of decisions. +6. **Sample instead of disabling.** Sample rates move the cost without giving up the signal + entirely. +7. **On React Native, check for double initialization** (see above). It is easy to hit and + easy to fix. +8. **Capture a trace and see where the time lands.** See + [Attribute the cost with a trace](#attribute-the-cost-with-a-trace). Distinguishing + `DdRumContentProvider` from `Datadog.initialize()` from your own startup work changes what + you do next. + +### Getting help + +If you've worked through that list and the number still doesn't make sense, open an issue on +[dd-sdk-android](https://github.com/DataDog/dd-sdk-android/issues/new/choose) or contact +[Datadog Support](https://docs.datadoghq.com/help/). Please include: + +1. **Proof the SDK was live in the treatment arm** — the `datadog-*` thread list from + [Step 3](#step-3--prove-the-sdk-is-actually-running). +2. **Your A/A validation output** — this is what tells us the numbers are trustworthy. +3. **Confirmation both builds were release-configured**, and the `aapt2 dump badging` output + showing matching `versionCode` / `versionName`. +4. **The raw CSV**, every launch, warm-ups marked rather than deleted. +5. **`ab_stats.py` output** — the paired block delta, its CI, the per-block breakdown and the + MDE. +6. **Device details** — exact model and Android version, confirming a physical device. +7. **Your SDK configuration** — features and sample rates, especially Session Replay. +8. **Perfetto traces** from both arms, captured with `capture_trace.sh` so they pass the + liveness check. Note what these contain before sending them — see + [What is in a Perfetto trace](#what-is-in-a-perfetto-trace). + +Items 1–5 are enough for us to reproduce and act on straight away. + +--- + +## Reference + +### Why the methodology is this careful + +Cold-start A/B benchmarking looks trivial and is not. The obvious approach — build two APKs, +launch each a few times, compare averages — reliably produces numbers that are **wrong by +more than the effect being measured**. + +These are real results from a mid-range device (Helio G95, Android 12) running **the same APK +in both arms**, so the true difference was zero by construction: + +| protocol | measured "difference" | 95% CI | p | verdict | +|---|---|---|---|---| +| fixed arm order, permission dialogs unhandled | **+12.7 ms** | [+3.0, +22.5] | **0.011** | **false positive** | +| counterbalanced order, dialogs unhandled | +5.0 ms | [−4.4, +14.4] | 0.30 | null, but noisy | +| counterbalanced + permissions pre-granted | **−0.8 ms** | [−6.9, +5.2] | 0.79 | correct | + +The first row is a *statistically significant* result on two identical builds. Anyone running +that protocol would have reported a regression that did not exist. + +None of this is exotic. It's the ordinary difficulty of measuring a small effect in a noisy +system, and it's why the steps above exist. + +> The figures published in [`sdk_performance.md`](sdk_performance.md) predate this harness and +> were produced with a lighter protocol — 5 launches per arm, fixed arm order, no A/A +> validation and no confidence intervals — on one reference app, SDK version, device and +> configuration. Treat them as indicative of scale only, not as a number to compare your own +> measurement against. Measure your own app. + +### Which controls bias the result, and in which direction + +Every control here was added to remove a known error source, and several of them remove +variance at the cost of a directional bias. Publishing the instrument without publishing that +trade-off would not be worth much, so: + +| control | variance it removes | direction it biases the measured SDK cost | +|---|---|---| +| forced compile at `speed-profile` | first-launch compilation *variability* — it pins a known state, identical across arms | **not downward, despite appearances.** On a freshly installed app there is no profile to compile against, so this lands at `status=verify` — **no AOT code at all**, and the startup path is JIT-compiled on every launch. Verify it rather than assume: `adb shell dumpsys package dexopt`. Relative to a steady-state Play install (cloud profile + `bg-dexopt`) this is *pessimistic*. `COMPILE_FILTER=speed` forces full AOT and **that** biases downward | +| discarding warm-up launches | first-run migrations, cold caches | **downward** — by the first measured launch the SDK's dex, oat and `libdatadog-ndk.so` are page-cache resident | +| `am force-stop` instead of reboot | process and system state | **downward** — force-stop does not evict the page cache, so page-in cost for the SDK's extra code is largely absent | +| TTID (`TotalTime`) as the endpoint | post-first-frame variance | **downward** for apps whose startup continues past first frame — SDK work landing after first frame is excluded entirely | +| pre-granting runtime permissions | accumulating permission dialogs | **downward relative to a first-install user**, accurate for a returning user. It is the returning-user path that dominates field metrics | +| animations off | frame-count variance during the launch transition | **downward for any per-frame SDK work** — fewer animated frames means fewer `Choreographer` callbacks for vitals and long-task tracking, and fewer Session Replay snapshots. Set `ANIMATIONS=1` to measure with them on and quantify this for your app | +| screen pinned on, stable charge state | environmental noise | **neutral** — no known directional effect | +| ABBA counterbalancing | drift across the session | **neutral** — removes an ordering bias that could point either way | +| paired block-level analysis | between-cell variance being ignored | **neutral** — widens the interval, does not move the point estimate | +| release builds, physical device | debug-build and emulator distortion | **corrective** — moves the measurement toward what users actually experience; direction depends on your app | + +**Net effect:** the number this harness produces is a good estimate of what a *returning* user +on a warm page cache experiences, to first frame, and a **lower bound** on what a first-install +or post-reboot user experiences. If you need the first-launch-after-install figure, reboot the +device between launches instead of using `am force-stop` and expect both a larger number and +much more variance. + +### Know what your metric actually measures + +`am start -W TotalTime` ends at the **first frame** of your launched activity. For React +Native, Flutter and other framework apps, a large part of startup happens *after* that — JS +bundle evaluation, bridge setup, first framework render. Within a single Perfetto trace of one +RN app, first frame landed ~963 ms after `bindApplication` while `setupReactContext` / +`attachRootViewToInstance` ran on to ~1838 ms, so `TotalTime` excluded more than half of real +startup. (Those two timestamps come from the same trace, so their *ordering* is sound; the +absolute values are not comparable to the A/B figures below, because a traced launch runs long +— see [Tracing changes what you are measuring](#four-things-that-will-mislead-you).) + +If most of your startup follows first frame, `TotalTime` will *understate* any SDK cost landing +in that later window. + +**Call `reportFullyDrawn()`** when your app is genuinely ready for interaction. Without it, +neither you nor any monitoring tool can measure time-to-fully-drawn. It costs one line and it +is the metric that reflects what users feel. The harness captures it as `ttfd` when the app +emits it, alongside `TotalTime` and logcat's `Displayed`. + +Two things to know before treating TTFD as the better number: + +- **TTFD ends wherever the app puts the call.** If that point sits behind a network request or + other I/O, the TTFD delta absorbs variance the SDK does not control. Check your A/A run's + TTFD interval: on the app above the TTFD noise floor was ~25 ms against a ~9 ms TTID floor, + so the wider window costs real resolution. TTID is the more tightly attributable of the two; + TTFD is the more complete. Report both. +- **It does not always fire.** On a fresh install where a runtime-permission dialog was still + pending, `reportFullyDrawn()` never fired at all and no `Fully drawn` line appeared, while it + fired on 64/64 launches of the same build once permissions were pre-granted. A `ttfd` column + that is `NA` everywhere usually means the app never reached its own ready state, not that the + metric is unavailable. + +When the app does emit it, analyse both windows — `ab_stats.py` takes `--metric`: + +```bash +./ab_stats.py results_.csv # total_ms (TTID), the default +./ab_stats.py results_.csv --metric ttfd # through to fully drawn +``` + +On one React Native app measured with this harness, TTID averaged ~630 ms while TTFD averaged +~2075 ms. First frame was under a third of startup, so a TTID-only comparison could not have +detected an SDK cost landing anywhere in the other two thirds. The noise floor differs too — +on that app the minimum detectable effect was ~9 ms on TTID and ~25 ms on TTFD, so the wider +window costs you resolution. Report both rather than choosing. + +### Attribute the cost with a trace + +An A/B delta tells you *how much*. A Perfetto trace tells you **what work exists and where** — +which is not the same as telling you where the cost is, and is emphatically not a second opinion +on the magnitude. Set expectations accordingly before you spend a day on this: on a real customer +app, traces of all three arms found no SDK work at all inside the window that carried most of the +measured cost. That was a useful answer, but it was not the answer the exercise was set up to get. + +```bash +cd tools/coldstart-benchmark +PKG= ./capture_trace.sh app-with-datadog.apk treatment 1 +./.venv/bin/python verify_trace.py treatment.pftrace --package +``` + +The third argument to `capture_trace.sh` is the arm's SDK expectation: `1` for the treatment +arm, `0` for the baseline. The capture is discarded if the expectation is violated. + +`verify_trace.py` exits `0` if the SDK is demonstrably active (or correctly absent), `1` if it +is not detected, and `3` if the trace is unusable — no `bindApplication` slice, meaning the +trace does not contain a cold start and cannot answer the question either way. + +Three requirements that are easy to get wrong: + +1. **`am force-stop` before tracing**, and launch *inside* the trace window. A trace with no + `bindApplication` slice contains no cold start. +2. **Enable full process stats.** With a bare `linux.process_stats` data source, thread names + come only from scheduler events, so an idle thread is invisible — and you cannot conclude + the SDK is absent from the absence of its threads: + ``` + process_stats_config { scan_all_processes_on_start: true proc_stats_poll_ms: 1000 } + ``` +3. **Add `sched_blocked_reason`** to attribute I/O wait. + +Keep app content consistent between traces. A single trace per arm has no averaging, so one run +loading video while the other doesn't can swamp everything. In one real pair the difference was +~90 extra ExoPlayer/MediaCodec threads and +24.8% process CPU unrelated to the SDK. + +Don't cross-reference a JIT-mode trace with AOT-compiled benchmark numbers. If your trace shows +`Compiling baseline` slices, it wasn't AOT-compiled and the datasets aren't comparable. + +#### Four things that will mislead you + +**A trace of a different scenario is worse than no trace.** `capture_trace.sh` pre-grants runtime +permissions and refuses a capture the app did not stay in the foreground for, because both of +those went wrong on a real capture set. A permission dialog stopped the baseline app 1030 ms into +the launch; it produced no further frames and never reached `reportFullyDrawn()`, so the window +under study had no end in that arm — while both treatment arms ran to completion. Compared +naively, that is a large, entirely fictitious SDK cost. Liveness verification passes such a trace +without complaint: **a stopped app still has every one of its `datadog-*` threads.** + +**Tracing changes what you are measuring.** Perfetto is not free. On the app above, the +first-frame → `reportFullyDrawn()` window was ~101 ms longer (+7%) in *every* arm with tracing on +than the untraced A/B measured. The traced launch is a real launch, but it is not the launch your +benchmark numbers describe. + +**Don't derive magnitudes from traces.** Captures are slow, so you will have a handful per arm +where the A/B has 32. Five per arm resolved that same window only to about ±32 ms — wide enough +to swallow the effect being investigated. Use the A/B for how much, always. + +**Check *when* the work happens, not just how much there is.** On that app, ART JIT-compiled +~149 ms of SDK classes (~390 ms with Session Replay) — which looks like a headline startup cost +until you timestamp it. Zero of those compilations occurred before `reportFullyDrawn()`; the +first began 406–500 ms *after* it, in all ten traces. It is post-launch background CPU and costs +nothing on TTID or TTFD. Always locate work relative to your measurement endpoint before +attributing it to startup. (A single trace per arm had put the Session Replay figure at 443 ms; +ten traces settled it at ~390 ms. Quote the number you have the n for.) + +Related: if your app's startup ends on a vsync-paced animation, expect the tail of the window to +have per-frame slack that absorbs extra background CPU. Check the main thread's idle share and +device-wide CPU utilisation across the window before concluding that background work is +contending with anything. + +### Benchmarking the app's own startup metric + +Most teams already have their own startup trace and quote *that* number, not `TotalTime`. You +can A/B it directly: set `APP_TRACE_REGEX` to an extended regex matching the log line, and the +last number in the match is recorded per launch as `app_trace_ms`. + +```bash +APP_TRACE_REGEX='cold_launch_total duration: [0-9]+' \ + PKG= ./coldstart_bench.sh baseline.apk treatment.apk +./ab_stats.py results_.csv --metric app_trace_ms +``` + +This is worth doing before arguing about whose number is right, because **an app's own trace +often does not end where its name suggests.** One app's `cold_launch_*` trace, documented +internally as ending "at first frame", measured 806 ms on a launch where `am start -W` +reported `TotalTime: 667` — it ran ~140 ms past first frame. Comparing a delta from that trace +against a TTID delta is comparing two different windows, and the wider one will legitimately +show more SDK cost. + +Two checks before trusting any app-reported trace: + +1. **Confirm it emits at all**, on the device and build you are measuring. One trace in the + same app never appeared in 1381 logcat lines from a verified-live build — it was gated + somewhere. A number nobody can reproduce cannot be compared. +2. **Bound the window** by capturing `total_ms`, `ttfd` and `app_trace_ms` on the same launches. + The harness records all three, so the ordering is visible rather than assumed. + +### What the harness changes on your device + +`coldstart_bench.sh` needs a stable device to produce stable numbers, so it changes state. +It snapshots the original values first and restores them from an `EXIT` trap; `INT` and `TERM` +exit into that trap, so Ctrl-C stops the run *and* restores the device, once. +`capture_trace.sh` does the same for the animation scales, screen settings and its own +permission grants, and also uninstalls and reinstalls the app — so it destroys app data too. + +| what | why | +|---|---| +| **uninstalls and reinstalls your app** before every arm of every block (and once in `verify_sdk_active.sh`, and once in `capture_trace.sh`) | guarantees a known install state and lets the md5 attestation prove which APK is being measured. **This deletes all app data.** With the default 8 blocks that is 16 uninstall/install cycles | +| pre-grants every runtime permission your app declares | removes the accumulating-dialog contamination. Only these grants are revoked on exit — never a device-wide `pm reset-permissions`, which would also drop every *other* app's grants | +| `window_animation_scale`, `transition_animation_scale`, `animator_duration_scale` → 0 | animation time is not startup time. All three are snapshotted and restored individually | +| `stay_on_while_plugged_in`, `screen_off_timeout` | the screen must stay on for the whole run | +| Wi-Fi on (default), or Wi-Fi **and** mobile data off when `AIRPLANE=1` | both arms must see the same network state. The default path turns Wi-Fi **on** even if you had it off, so `wifi_on` and `mobile_data` are snapshotted and put back | +| `cmd package compile -m -f` | a stable AOT profile | + +The app is left installed when the run finishes. Remove it with +`adb uninstall ` if you want a clean device. + +### What is in a Perfetto trace + +`capture_trace.sh` captures **device-wide** data, not just your app: process and thread names +for everything running, scheduler activity, and window/activity transitions across all apps. +Anything running on the device during the capture — other apps, notifications, system services +— appears in it. + +Review a trace before attaching it to a support ticket or sharing it, and prefer capturing on +a device without unrelated accounts or apps signed in. The benchmark CSV and `ab_stats.py` +output contain no such data and are safe to share as-is. + +### Common pitfalls + +| symptom | likely cause | +|---|---| +| delta far larger than the SDK could plausibly cost | debug build — see [Step 1](#step-1--build-apks-that-represent-what-you-ship) | +| numbers wildly larger than expected across the board | running on an emulator — see [Step 2](#step-2--use-a-physical-device-not-an-emulator) | +| A/A run shows a significant difference | fixed arm order; counterbalance it | +| high variance drifting over the run | permission dialogs stacking; pre-grant them | +| "with SDK" arm identical to baseline | SDK never initialized — see [Step 3](#step-3--prove-the-sdk-is-actually-running) | +| first block differs wildly from later blocks | not AOT-compiled, or too few warm-ups | +| `TotalTime` empty and `LaunchState=UNKNOWN` on every launch | the device is locked, or the notification shade is on top. Unlock it and leave it on the home screen | +| every launch reports the wrong foreground activity | your `dumpsys` grep is anchored on `mResumedActivity`; this device prints `ResumedActivity:`. Match `m?ResumedActivity[:=]` | +| `ab_stats.py` refuses to print a CI | fewer than 3 complete blocks; re-run with more | +| `ab_stats.py` refuses the file entirely | the run aborted, or the CSV holds fewer blocks/launches than its own header says (a `kill -9` or power cut skips the abort marker). Re-run; `--allow-aborted` inspects it diagnostically | +| the harness refuses to start, naming a package mismatch | `PKG` is not the application id the APKs declare. Fix `PKG` — do not work around it; every block runs `adb uninstall $PKG` | +| the harness refuses to start on differing `versionCode`/`versionName` | the arms are different app versions, so the SDK is not the only variable. Rebuild both from one commit, or set `ALLOW_VERSION_MISMATCH=1` if you know why they differ | +| `displayed` or `ttfd` is `NA` on every row | the app doesn't call `reportFullyDrawn()` (for `ttfd`), or a vendor logcat format; `total_ms` is still valid | +| `verify_trace.py` exits 3 | no `bindApplication` slice, so the launch is not in the trace window: `force-stop` the app before tracing and start it inside the trace | +| trace shows no SDK activity | no `force-stop` before tracing, or a bare `process_stats` data source | +| `ModuleNotFoundError: perfetto` | running `./verify_trace.py` with the system interpreter; use `./.venv/bin/python verify_trace.py` | +| numbers don't match your field metrics | different measurement window (`TotalTime` vs your RUM metric), debug vs release build, page-cache-warm vs genuine first launch, or device mix | From 652dbe8e37e866d478db11d7bd15fa39ac064003 Mon Sep 17 00:00:00 2001 From: Valentin Pertuisot Date: Fri, 21 Aug 2026 16:26:58 +0200 Subject: [PATCH 3/3] RUM-18135: Add a coldstart-benchmark skill for coding agents MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Same protocol as the guide, written for an agent driving the investigation rather than a human reading it end to end: ordered steps, hard gates, and the measured cost of skipping each control. It exists because the failure mode this work exposed is an agent (or a person) producing a plausible number from a broken protocol and reporting it. The skill front-loads the two gates that catch that — prove the SDK initializes, then A/A the protocol — and refuses to treat an A/B as meaningful until both pass. Also carries the attribution rules that are easy to get backwards: what each verify_trace.py exit code licenses you to conclude, why a stopped app still passes a liveness check, and why work has to be timestamped against the measurement endpoint before it can be called a startup cost. Ships in the repository so a clone picks it up, and makes no assumption about whether the app being measured is ours or a customer's. --- .claude/skills/coldstart-benchmark/SKILL.md | 280 ++++++++++++++++++++ 1 file changed, 280 insertions(+) create mode 100644 .claude/skills/coldstart-benchmark/SKILL.md diff --git a/.claude/skills/coldstart-benchmark/SKILL.md b/.claude/skills/coldstart-benchmark/SKILL.md new file mode 100644 index 0000000000..83bbb8edf0 --- /dev/null +++ b/.claude/skills/coldstart-benchmark/SKILL.md @@ -0,0 +1,280 @@ +--- +name: coldstart-benchmark +description: Use when measuring the Datadog Android SDK's cold-start impact on an app — your own or one you are supporting — when app start got slower after adding the SDK, or when checking whether a cold-start A/B benchmark can be trusted. Enforces the liveness check, A/A validation and statistical controls that uncontrolled benchmarks miss. +--- + +# Datadog Android SDK — Cold-start benchmarking + +## Overview + +Cold-start A/B benchmarking looks trivial and is not. An uncontrolled protocol produces +numbers that are wrong by more than the effect being measured. On identical APKs — true +delta zero — a fixed-arm-order protocol with unhandled permission dialogs reported +**+12.7 ms, 95% CI [+3.0, +22.5], p = 0.011**: a statistically significant regression that +did not exist. + +**Core principle:** never trust an A/B result until you have (a) proven the SDK actually +initializes in the treatment arm, and (b) run the same APK in both arms and confirmed the +result is null. + +Scripts: [`tools/coldstart-benchmark/`](../../../tools/coldstart-benchmark). The same +material in prose, with more background: +[`docs/benchmarking_sdk_cold_start.md`](../../../docs/benchmarking_sdk_cold_start.md). + +This skill ships in the SDK repository so that anyone who clones it gets it — whether you +are measuring your own app or helping someone else measure theirs. It makes no assumption +about which. Where a step needs information only the app's owner has (build type, feature +flags, SDK configuration), ask for it rather than guessing. + +## When to Use + +- App start got slower after adding the Datadog SDK +- Measuring what the SDK costs at startup, before or after adopting it +- Deciding whether a benchmark result — yours or someone else's — can be trusted +- Auditing whether a Perfetto trace can support the conclusion drawn from it + +## Do these in order + +### 0. Reject the run before it starts if either of these is wrong + +**Release-configured builds.** Debug builds are not optimized, shrunk or obfuscated and +carry tooling users never run; their startup behaviour says nothing about production. +Require `isMinifyEnabled = true`, `isDebuggable = false`, release signing, production R8 +rules, matching `versionCode`/`versionName` on both arms. A number from a debug build is +not a measurement of the SDK — establish the build type before analysing anything else. + +**Physical device.** Emulator numbers are worthless for this question — a laptop core is +many times faster than a mid-range phone core, on an SSD, with no big.LITTLE scheduling and +no thermal throttling, which distorts exactly the phases in play. No correction factor +recovers the real answer. The harness stamps `emulator=1` and warns, but the run should not +happen at all. + +### 1. Prove the SDK initializes at all + +Most likely single cause of a nonsensical benchmark. A build that *contains* the SDK is not +a build that *initializes* it: feature flags, remote config, experiment buckets, consent +gating and deferred init all leave it compiled in but inert. This is not hypothetical: an +"SDK enabled" build whose initialization was gated off by a host-app feature flag invalidated +every measurement made against it, on both sides, before anyone noticed. + +**The oracle.** `CoreFeature.initialize()` calls `setupExecutors()` then immediately submits +the NTP-sync task to `persistenceExecutorService` +(`dd-sdk-android-core/src/main/kotlin/com/datadog/android/core/internal/CoreFeature.kt:265-266`). +That executor uses `DatadogThreadFactory`, which names threads +`datadog--thread-`, truncated by Linux to 15 chars (`datadog-storage`). The name +is built at runtime from a string template, so **R8 cannot rename it**. A completed +`Datadog.initialize()` therefore always leaves at least one `datadog-*` thread. + +```bash +tools/coldstart-benchmark/verify_sdk_active.sh +``` + +This installs, md5-attests the install against the local file, launches via the real launcher +intent, settles (`SETTLE`, default 20s), then reads `/proc//task/*/comm`. Exit 0 = live, +1 = not, 2 = setup failure (no adb, no device, missing APK). + +If it reports not-live, check logcat for SDK errors and for host-app gating: + +```bash +adb shell logcat -d | grep -iE 'datadog|DD_SDK' +``` + +`libdatadog-ndk.so` in `/proc//maps` is corroborating only — the SDK loads it with a +plain `System.loadLibrary`, which does not reliably emit a trace slice. + +### 2. Validate the protocol with an A/A run + +Same APK in both arms. True delta is zero, so whatever comes out is the protocol's error. + +```bash +cd tools/coldstart-benchmark +PKG= EXPECT_B=0 LABEL_A=A1 LABEL_B=A2 \ + ./coldstart_bench.sh baseline.apk baseline.apk +./ab_stats.py results_.csv --baseline A1 --treatment A2 +``` + +`EXPECT_B=0` because both arms are the baseline APK; to A/A the treatment APK, use +`EXPECT_A=1 EXPECT_B=1`. + +Pass: the paired block CI straddles zero, the order effect is not significant, and the MDE is +small enough to detect the effect the A/B is looking for. **Do NOT require per-block deltas to +share a sign** — the true delta is zero, so they should straddle it; unanimity across 8 blocks +happens <1% of the time and indicates directional bias, not cleanliness. +**If A/A fails, no A/B number from that setup means anything.** + +### 3. Run the A/B + +```bash +PKG= ./coldstart_bench.sh baseline.apk treatment.apk +./ab_stats.py results_.csv +``` + +Defaults are 4 runs × 8 blocks (32 measured launches per arm, ~1 hour). `coldstart_bench.sh` +aborts if the treatment arm has no `datadog-*` threads, if the baseline arm unexpectedly has +some, or if any measured launch is not `LaunchState=COLD` / `Status=ok` with the app in the +foreground afterwards. + +Give Session Replay its own arm — but do not assume the answer. It is the heaviest feature +while a session is recording; that is not the same as being heavy at **startup**. Measured on +a React Native app (8×4, 32 launches/arm, mid-range device), enabling it added +8.9 ms TTID +(CI [−3.2, +21.0]) and +10.0 ms TTFD (CI [−20.7, +40.6]) — not separable from zero — against +a core-SDK cost of +24.7 / +78.7 ms. If disabling Session Replay does not move the number, +the cost is in the core SDK. + +### 4. Attribute with a trace (optional) + +```bash +PKG= ./capture_trace.sh treatment.apk treatment 1 +./.venv/bin/python verify_trace.py treatment.pftrace --package +``` + +Use the venv interpreter — `verify_trace.py`'s shebang is the system `python3`, which will +not see a venv-installed `perfetto`. + +## Controls the scripts enforce, and why + +| control | failure it prevents | measured cost of omitting | +|---|---|---| +| paired per-block analysis | pooling launches ignores between-cell variance | 2×15 unpaired false-positives 23% of the time at a 4 ms between-block shift; 8×4 paired holds at 5%. Reproduce: `./fp_simulation.py` | +| ABBA arm order | fixed order turns session drift into a fake treatment effect | manufactured a significant +12.7 ms on identical APKs | +| pre-grant runtime permissions | prompt reappears each launch and instances accumulate | 23 stacked dialogs; ~23 ms, and most of the 18.9 → 11.7 ms pooled-sd drop | +| foreground assertion, every launch | dialog/crash/ANR on top of the app | silently corrupted two full A/A baselines before it existed; contamination accumulates, so once-per-arm cannot see it | +| `LaunchState`/`Status` assertion | averaging a warm launch into a cold-start number | — | +| md5 attestation of the install | measuring a build you didn't intend | invalidated an entire trace pair | +| `compile -m speed-profile -f` + discard warm-ups | no AOT profile makes early launches slow and erratic | first-block means differed by ~17 ms | +| real launcher intent | `am start -n ` isn't an icon tap | wrong code path on apps that route the launcher through activity aliases | +| pre-registered warm-up count | post-hoc outlier dropping | turned a null into a "finding" in one report | +| device-state snapshot + restore trap | leaving a device with no lock screen, animations off, Wi-Fi flipped on and permissions granted | — | +| `aapt2` preflight on both APKs (mandatory; both scripts) | `PKG` naming a different app than the APKs (every block runs `adb uninstall $PKG`), or arms built from different app versions | — | +| launcher resolved *after* each install | resolving up front cannot work on a clean device, and silently reuses a component read off a leftover build when one is installed | — | + +## Reading the statistics + +`ab_stats.py` prints all of this. The rules: + +- **The paired block-level delta is the primary endpoint.** Launches inside one arm×block + cell share an install, an AOT compilation and a thermal state, so an unpaired test over + pooled launches estimates the SE from within-cell scatter only and is anti-conservative. + ABBA removes the ordering *bias*; it does nothing about this variance underestimate. The + Welch numbers are printed as `[diagnostic]` for contrast, not for reporting. +- **Blocks buy power, runs per block buy less of it.** The CI narrows with √(blocks). Below + 3 complete blocks `ab_stats.py` refuses to print an interval at all — at 2 blocks + `t_crit(df=1) = 12.7`, which cannot support any significance claim. +- **Report mean and median.** If they disagree materially the distribution is skewed and + neither stands alone. One dataset: mean +8 ms, median +40 ms — a fivefold swing on + statistic choice. +- **Never quote a bare average.** A 4-run-per-arm dataset had a 95% CI of + **[−106, +122] ms** — it could not distinguish 0 from 120 ms. +- **Check MDE before believing a null.** "No significant impact" from an under-powered run + means "the run couldn't have detected it either way". The script computes required blocks from the + run's own between-block sd; don't transplant a required-n between apps or devices. +- **Per-block deltas straddling zero is normal**, not a warning, whenever the effect is + comparable to the between-block sd. Judge spread by the CI and MDE, never by sign counting. +- The order-effect test **refuses to report** when arm and position are confounded. With a + single block, arm A is always first, so any "order effect" *is* the treatment effect — + previously this reported a genuine +30 ms regression as an ordering artefact. It is also + **paired on blocks**, like the primary endpoint: one `2nd − 1st` delta per block, so it cannot + manufacture an order effect out of cell-level shifts. ABBA makes the treatment effect cancel + out of those deltas. +- **Concatenating CSVs from different devices or protocols is refused** (`--allow-mixed` to + override). Namespacing block ids stops blocks merging; it does not make two experiments + comparable. + +## Where the SDK's startup cost comes from + +These are the real contributors. State them plainly in any writeup — they are all +discoverable from a trace or from StrictMode, so a result that omits them reads as +incomplete rather than favourable. + +- **dex/APK growth** → extra class loading and verification, independent of init +- **`DdRumContentProvider` runs before `Application.onCreate`** whether or not + `Datadog.initialize()` is called (registered in + `dd-sdk-android-internal/src/main/AndroidManifest.xml`), so an "SDK disabled" build is not + a zero-cost build +- **deliberate main-thread disk I/O at init** — `CoreFeature.kt:275`, + `NdkCrashReportsFeature.kt:55` and `:111`, plus Session Replay's requirement checkers. + `StrictModeExt.kt` exists specifically to suppress StrictMode for these, so "no additional + I/O" is not an accurate description — StrictMode or `sched_blocked_reason` will show it. +- **executor/thread creation at init**, which competes for cores on low-end devices +- **per-frame callbacks** when vitals or long-task tracking are on +- **Session Replay** — heaviest feature during a recording session, but its measured + *startup* increment on one React Native app was ~9 ms and inside the noise. Measure it in + its own arm rather than assuming either way + +On React Native, check for **double initialization** — native in `Application.onCreate` and +again from JS. The core guards re-init, but `DdSdkImplementation.initialize` has no early +return: it rebuilds its configuration, and `enableJankStatsTracking` plus the +`Choreographer.FrameCallback` in `FrameRateProvider` are **not** guarded. + +## Bias direction of the controls + +Every discretionary control removes variance, and most bias the measured SDK cost *downward*. +Full table in the +[guide](../../../docs/benchmarking_sdk_cold_start.md#which-controls-bias-the-result-and-in-which-direction). +The short version: forced AOT, discarded warm-ups, `am force-stop` (which does **not** evict +the page cache), TTID-only measurement and pre-granted permissions all shrink the number. The +metric is a **process-cold, page-cache-warm** start to first frame, and is closer to a lower +bound than a worst case. Quote it with that caveat attached. + +## Trace gotchas + +`verify_trace.py` returns three outcomes, and the distinction matters: + +| exit | meaning | +|---|---| +| 0 | SDK active — or correctly absent, with `--expect-absent` | +| 1 | SDK **not** active, or the process/package is not in the trace. Sound as a negative *only* because the trace contains the cold start | +| 3 | trace unusable — no `bindApplication`, so no launch in it at all | +| 4 | with `--require-foreground`: something else owned the foreground *during* the capture. The SDK may be active; the trace is just not the scenario the benchmark measured | + +Why: the thread oracle's *absence* only proves something when init ran inside the trace +window. With a bare `linux.process_stats` data source, thread names come only from scheduler +events, so an idle `datadog-*` thread is invisible and absence proves nothing. +`capture_trace.sh` sets `scan_all_processes_on_start: true` and `record_thread_names: true` +to fix this, and `verify_trace.py` reports whether the trace enumerates idle threads so a +negative can be distinguished from an inconclusive. + +The oracle is scoped to the app's own `upid` and **requires** a `datadog-*` thread. Matching +any slice or path containing "datadog" would false-positive unconditionally on this repo's own +sample apps. + +Also: `am force-stop` before tracing or there is no cold start; keep app content consistent +(one real pair differed by ~90 ExoPlayer/MediaCodec threads and +24.8% CPU); and never +cross-reference a JIT trace (`Compiling baseline` slices present) with AOT-compiled benchmark +numbers. + +**Timestamp work before calling it a startup cost.** The single biggest block of SDK CPU we +have measured — ~149 ms of `com.datadog.*` JIT, ~390 ms with Session Replay, across ten traces — +turned out to be **post-launch** background CPU: zero compilations began before +`reportFullyDrawn()`, the first started 406–500 ms after it, in all ten traces. It costs nothing +on TTID or TTFD. Locate work relative to the measurement endpoint before attributing it, and +report the n: a single trace per arm had put the Session Replay figure at 443 ms. + +`capture_trace.sh` captures **device-wide** process, thread and window data from every running +app. Check what a trace contains before attaching it to a ticket or sending it to anyone. + +## Measurement-window trap + +`am start -W TotalTime` ends at **first frame**. For React Native and Flutter apps much of +startup follows — in one measured case first frame at ~963 ms while framework bring-up ran to +~1840 ms. `TotalTime` therefore *understates* any SDK cost landing after first frame. +Recommend the host app call `reportFullyDrawn()`; without it TTFD is unmeasurable by anyone. +The harness records `total_ms`, `displayed` (TTID from logcat) and `ttfd` separately. + +`displayed` must be extracted anchored on the AOSP `ActivityTaskManager: Displayed /…` +format — some vendors (e.g. Motorola) log their own `MotoDisplayed` line first, and an +unanchored `grep -m1` picks that one and silently yields `NA` on every row. + +## Device caveats + +- Never compare emulator to device, or across device models. Emulators inflate exactly the + phases in question (native library loading, dex verification, disk I/O, thread contention) + and have no thermal throttling. +- `dumpsys thermalservice` returns **stubbed values on some devices** — five consecutive + byte-identical snapshots have been observed. A flat reading is not evidence of no drift. +- Perfetto callstack sampling and heap profiling need `` + or a debuggable build; on a `user` build, neither flag means an empty profile. App and + framework atrace slices — including `bindApplication` — are captured regardless. Without a + profileable build you get phase-level attribution, not method-level. +- `AIRPLANE=1` is a misnomer: it uses `svc wifi/data disable`, not airplane mode, and + `svc data disable` needs root on most retail devices.