mirror of
https://github.com/software-mansion/argent.git
synced 2026-09-14 19:27:14 +08:00
filip131311
9e45b98135
Fixes #619. ## Reproduced, then verified, on the reporter's own session Their artifacts were still on disk (`react-profiler-20260731-150333`: 1873 samples, 25114.0 ms, one hot commit at t=12307.5 ms), so every number below is from the session in the issue rather than a fixture. ## Two defects **Self-time was the question, not the answer.** `avgIntervalMs = (endMs - startMs) / totalSamples`, so self-time = *requested window width* × share of hits. Same samples, three windows, three answers: ``` [0, 25114] → createAnimatedNode 29.12 [0, 50000] → 2× [0, 100000] → 4× ``` **Samples were displaced by the first hot commit.** `clockOffsetMs = firstCommitTimestampMs - cpuStartMs`, applied when `|diff| > 1000`. `startTime` is a since-boot monotonic value (1_276_275_277_894 µs ≈ 14.8 days), so that guard is *always* satisfied and the offset was *always* the first hot commit — 12307.5 ms here, which is exactly how far every sample moved. **Together they predict the reported 2×**: displaced samples covered `25114.0 − 12307.5 = 12806.5` ms of a full-range query, so `25114.0 / 12806.5 = 1.961`. The reporter measured `completeRoot` 52.87 vs 26.82 — a ratio of 1.971. ## The fix **Clock: subtract, don't infer.** React DevTools emits every commit as `performance.now() - profilingStartTime`, so commit timestamps are already ms-since-profiling-start. Sample times are now the same thing — `(accumulatedUs - startTime) / 1000` — and `buildCpuSampleIndex` no longer accepts a commit timestamp at all, so the inference cannot come back. **Weights: each sample's own interval, clipped to the window.** A sample stands for the interval that *ended* at it, so a window cutting through one counts only the part inside. That gives four properties the old formula had none of: independent of the requested bounds, additive across adjoining windows, bounded by the window (a 45 ms commit can no longer be credited with more than 45 ms), and summing to the profile's own duration. Per-sample rather than averaged because the sampler is not isochronous — measured on the real profile, deltas run 0–36.6 ms around a 13.1 ms median. An average smears a stall evenly across every function in the window. *(A note on my own reasoning: I initially justified per-sample weighting with a synthetic fixture showing a 20× cost difference reported as a tie. That demonstrates the mechanism but overstates it — real Hermes sampling is roughly periodic, so the effect is a redistribution, not a rank inversion. The durable arguments are window-invariance and additivity.)* **Finding nothing now says which kind of nothing.** Outside the recorded range; inside it but unreached by any sample; a profile with no samples at all; and — the case that actually dominates — a window **fully covered by samples that were all idle**. 99% of samples in this session were idle, so a window can be completely covered and still rank nothing. Reporting that as "no CPU hotspots found" is what made a miss read as "this commit was cheap". Every table now states what it measured: sample count, covered ms, idle ms, and the sampling interval — plus a warning when the window is narrower than ~3 intervals, or when a sampler stall lands wholly on one function. **The on-disk index is versioned.** A file written before this change holds displaced timestamps and no interval starts; reusing one would answer from cache with exactly the numbers being removed. Readers reject it and rebuild from the raw profile, which is always retained. The same validation stops a truncated index deserializing into an empty profile that would answer "no hotspots" forever (`new Float64Array(undefined)` is silently empty). ## The reporter's five queries, after ``` 12300–12345 → recordProfilingDurations 15.05ms, completeRoot 4.86ms (was: nothing) 10000–15000 → 371 samples, real hotspots (was: nothing) 0–1000 → 71 samples, 1000.0ms covered, ALL IDLE — stated (was: nothing) 24000–25114 → 85 samples, 1113.1ms covered, ALL IDLE — stated (was: touch events from t≈12s) 0–25114 → 1872 samples, 25113.1ms covered, self-times correct (was: 2×) ``` Two remain empty — correctly, and they now say why. ## Tests 15 new cases in `test/react-profiler/cpu-correlate.test.ts`, all pure. There was **no test at all** for either file before, which is why this survived. Covered: window invariance across four widths, sub-window partitioning, boundedness by window width, additivity, per-interval weighting, rebasing a since-boot start time, coverage within one interval of the profile's reported duration, defensive deltas (missing/negative/NaN), the four empty-window shapes, and index round-trip plus v1/truncated rejection. Mutation-verified: restoring the window-derived average fails 8 of 15. Full tool-server suite green — 3101 passed / 298 files. ## Behaviour change — worth calling out in the release notes Numbers move in both directions. Windowed self-times fall by the ratio of the window to its sampled coverage; previously-empty windows now return data; and per-commit CPU blocks in **every** analyze report change wholesale, because they were reading a region of the profile the commit never occupied. **Any before/after optimisation baseline recorded with the current build must be re-measured.** ## Not in scope - **`time-align.ts:50-58` has the same family of bug** — `buildReactAnchor` sets `monotonicStartMs` from the since-boot `cpuProfileStartTimeUs` while commit timestamps are profile-relative, so commits are projected ~device-uptime into the past and **no hang can ever correlate with a commit**. It is invisible to the existing test because that test passes `cpuProfilePath: null`. Filing separately: fixing it makes `buildReactAnchor`'s second parameter and a `readCpuProfile` call dead, so it is not the one-liner it looks like. - `queryCpuWindow` emits one row per *node id*, so a function reached via several call paths is listed repeatedly with its cost split. Real, and moves numbers again — separate issue. - `component_cpu` applies its top-50 cut per window *before* aggregating, truncating the long tail. - `renderCallTree` and `react-profiler-cpu-summary` still derive self-time their own ways; unifying them onto these weights is a follow-up. - Hermes ignores the requested `sample_interval_us` (100 µs requested, ~13.4 ms observed). Not argent's bug, but it is why no fix may derive an interval from the requested config.