feat(size): Log per-insight timing in Apple analyzer - #665
Conversation
Insight generation emitted no progress logging, so a slow insight was invisible in traces (it looked like a silent hang). Log each insight's wall-clock duration on completion (size.apple.insight_completed with the insight name and elapsed_s) so the expensive phase is attributable.
📲 Install BuildsiOS
Android
|
Size Analysis2 components analyzed iOS Builds
Android Builds
|
| with sentry_sdk.start_span(op="insight", description=f"apple.insights.{insight_name}"): | ||
| return insight_class().generate(insights_input) | ||
| started = time.monotonic() | ||
| result = insight_class().generate(insights_input) |
There was a problem hiding this comment.
Am fine if we want to keep this for logging purposes but I'm a bit confused why we need it when we have span information right above? Can't we just look at the span timings in the trace to figure out the same thing?
There was a problem hiding this comment.
for a run that completes, the span indeed covers it. The log is for the timeout case: when a task is killed at the deadline mid-insights, the transaction is truncated and the running insight's span never closes, so the trace can't tell you which insight was grinding.
The logs flush per-insight as each finishes, leaving a durable trail up to the kill, which was missing in the case of the customer's build.. so it seems nice to add just in case - at least as long as timeouts still occasionally happen in prod
2 participants
Insight generation logged nothing per-insight. On a large anonymized iOS app that timed out,
size.apple.generate_insightswas the last log before silence — a slow insight was indistinguishable from a hang.This logs each insight's duration on completion:
size.apple.insight_completedwithinsightandelapsed_s.It's observability-only, so there's no material speedup and none measured (460.7s vs 439.8s, within noise). What it buys is attribution: it immediately isolated the culprit —
image_optimizationwas 129.06s of 129.3s insights (99.8%), while the other 11 summed to ~0.27s.Tested with a unit test asserting the completion log fires with the insight name +
elapsed_s, plusmake check.