perf(size): Parallelize Apple binary analysis across processes - #663
Conversation
📲 Install BuildsiOS
Android
|
Size Analysis1 component analyzed, 1 component processing iOS Builds
Android Builds
|
d5a4cfc to
23b4533
Compare
NicoHinderling
changed the title
![cursor[bot]](https://avatars.githubusercontent.com/in/1210556?s=60&v=4){kind=small}
975e07a to
08d44f0
Compare
![sentry[bot]](https://avatars.githubusercontent.com/in/12637?s=60&v=4){kind=small}
i did a simple solution for this for now: "Time each binary's analysis inside the worker that runs it and return that duration with the result, so the parent's per-binary "completed" log carries an accurate elapsed_s even though the log lines are emitted together." If we do land this PR, I'd plan to cut a followup PR to make sure that all the subprocess logs are piped back to the parent process for o11y convenience (ex. all trace info would stay intact) |
e1d2f05 to
d14c6f9
Compare
| binary = self._analyze_binary(binary_info, app_bundle_path, lief_cache) | ||
| self._log_binary_started(binary_info, app_bundle_path, extract_dir) | ||
|
|
||
| if workers > 1: |
There was a problem hiding this comment.
Does this happen frequently? I imagine basically all apps at this point have more than one binary in them and we don't need to special-case this which will help simplify things a bit.
There was a problem hiding this comment.
The more relevant part is whether we want to slow roll this out and keep the old logic side-by-side. I didn't see mention of a rollout plan in the description, are we going to hard cut over?
There was a problem hiding this comment.
as for rollout, I was planning to merge but pause the pipeline so it only deploys to s4s2 and do some manual testing before fully rolling it out
The more relevant part is whether we want to slow roll this out and keep the old logic side-by-side.
I don't plan on doing a slow rollout. I've tweaked the logic to keep the old path if LAUNCHPAD_BINARY_ANALYSIS_WORKERS=0
that way we can killswitch it if we need to by setting that env var to 0
if all goes well, i'll clean up the old path in a week or something
There was a problem hiding this comment.
before kicking this back for you to review again though, ill investigate wiring up sentry-options into launchpad :loading:
There was a problem hiding this comment.
#668
https://github.com/getsentry/sentry-options-automator/pull/9596
https://github.com/getsentry/ops/pull/23267
i've posted and sent ken these PRs to enable sentry-options within launchpad. Assuming he reviews them before eod, I'll merge and then switch the code to use this instead of the env var for convenience
I wont merge until eod but for now the env var = 0 killswitch should be valid
| f"Found dSYM file for {binary_info.name} at {binary_info.dsym_path.relative_to(artifact.get_extract_dir())}" | ||
| ) | ||
| binary = self._analyze_binary(binary_info, app_bundle_path, lief_cache) | ||
| self._log_binary_started(binary_info, app_bundle_path, extract_dir) |
There was a problem hiding this comment.
This logging is kind of awkward now since this for loop is purely to log everything at once. Could we maybe push these logs into _run_and_time itself so they come in when the analyzing actually happens? Otherwise I could see it being confusing that they don't actually align with when the work actually happened.
There was a problem hiding this comment.
i was considering doing this as a follow up pr but ended up just doing the bigger change now
workers now get a QueueHandler and the parent drains the queue and re-emits through its own handlers with the request id attached. So the per-binary started/completed logs fire inside the worker at the moment of the work, and both parent-side loops are gone.
Workers also return start/end timestamps and the parent rebuilds the per-binary span from them, so the trace waterfall shows real overlap.
| }, | ||
| ) | ||
| gc.collect() | ||
| self._log_binary_completed(binary_info, binary, elapsed) |
| logger.debug(f"Analyzing binaries in parallel with {workers} processes") | ||
| artifact.get_lief_cache().clear() | ||
| analyze = partial(self._analyze_binary, app_bundle_path=app_bundle_path, lief_cache=None) | ||
| executor = ProcessPoolExecutor(max_workers=workers, initializer=_binary_worker_init) |
There was a problem hiding this comment.
Can we confirm the peak memory usage here too, I would need to dig further but if it forks the parent process it could get pretty high.
There was a problem hiding this comment.
it doesn't fork the parent. agent test in the exact prod image that Python 3.14 on Linux defaults to forkserver, and nothing in launchpad overrides the start method. Forkserver workers are forked from a small helper process that starts fresh, not from the parent, so they inherit none of the parent's heap. I measured an idle worker at 15 MB earlier today. Each worker's memory is just the binary it's parsing.
There was a problem hiding this comment.
Measured peak memory properly this time: sum of RSS across the parent and every descendant, sampled every 0.5s, on the large app.
| Path | Peak tree RSS |
|---|---|
In-process (LAUNCHPAD_BINARY_ANALYSIS_WORKERS=0) |
2.44 GB |
| 4 workers (default) | 2.53 GB |
~90 MB more, under 4%. The peak is dominated by parsing the single largest binary, which happens in one process either way; the other binaries in flight are small next to it.
27cd376 to
40f4f41
Compare
There was a problem hiding this comment.
Cursor Bugbot has reviewed your changes and found 1 potential issue.
There are 2 total unresolved issues (including 1 from previous review).
❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, enable autofix in the Cursor dashboard.
Reviewed by Cursor Bugbot for commit 876afea. Configure here.
|
|
||
| class _TimedBinary(NamedTuple): | ||
| binary: MachOBinaryAnalysis | None | ||
| started_at: float |
There was a problem hiding this comment.
nit: is float right? i think what you had before with the monotomic timing was correct
| if self._thread.is_alive(): | ||
| logger.warning("Worker log relay did not stop; a worker was likely killed mid-write") | ||
|
|
||
| def _drain(self) -> None: |
There was a problem hiding this comment.
I feel like there's got to be a much simpler way to do this but not sure the best practice. Like could we just pipe the stderr and stdout back to the main process and append the logs?
The per-binary Mach-O analysis loop ran strictly serially, so on apps with hundreds of embedded binaries it dominated wall-clock time. The per-binary work is CPU-bound Python (LIEF parsing, symbol sizing, Swift demangling), so it is parallelized with a ProcessPoolExecutor to bypass the GIL — a thread pool was tried first and regressed, since threads can't parallelize GIL-bound Python. Worker count defaults to min(8, cpu_count), overridable via LAUNCHPAD_BINARY_ANALYSIS_WORKERS (1 forces the old serial path). Workers re-parse each binary from disk (the LIEF cache is not picklable); results are collected in input order, so binary_analysis and the treemap are unchanged (new serial-vs-parallel equivalence test). Timeout safety: a worker wedged in a native LIEF call ignores SIGTERM, so the pool's graceful shutdown cannot stop it. On timeout/error we SIGKILL workers directly, and on Linux each worker sets PR_SET_PDEATHSIG=SIGKILL so it dies with the parent if the job is force-killed — no orphaned workers. Also fixes a latent crash where the completion log dereferenced a None result. Trade-off: peak memory rises with worker count.
Addresses review feedback on the parallel binary-analysis path: - Pin the outer worker default to 4 (the pod's whole-core CPU request) instead of min(8, os.cpu_count()); there is no CPU limit, so cpu_count reads node cores and oversubscribes. Env override still wins. - Disable per-binary demangle parallelism inside workers, so the outer pool can't multiply into dozens of concurrent cwl-demangle subprocesses. - Clear the parent's LIEF cache before the pool runs; workers re-parse from disk, so the retained trees were dead weight held for the whole run. Add a forkserver test so the prod start method (which pickles the analyzer and binaries) is exercised; the fork default masked pickling. Harden the force-kill test's wait to poll rather than assume a single 5s window.
The backstop was meant to reap a LIEF-wedged worker if the parent died without running cleanup. It does nothing under the forkserver start method that prod uses (Python 3.14): the worker's parent is the forkserver helper, not the main process, so main's death never triggers the death signal. Verified on Linux/3.14 — the worker orphans with or without it. It was never load-bearing anyway. The 15-min deadline is an in-process SIGALRM raising ProcessingDeadlineExceeded in the task process, which is blocked in executor.map (pure Python, not wedged in C) and so always lands; our except BaseException runs _force_kill_pool, which SIGKILLs the workers directly regardless of start method. Keep the initializer for the demangle env var.
_force_kill_pool runs from the except block that re-raises the original failure (e.g. ProcessingDeadlineExceeded). Its executor.shutdown() was unguarded, so if it raised it would replace that exception. Workers are already SIGKILLed by then, so make the shutdown best-effort.
Parallelizing moved per-binary work into workers, so the started/completed log timestamps are now batched and per-binary duration couldn't be read from them. Time each binary inside the worker that runs it and surface the elapsed seconds in size.apple.binary_analysis_completed, so per-binary durations remain measurable in both the parallel and serial paths.
Python 3.14 exposes kill_workers(), which does exactly what the hand-rolled _force_kill_pool did (non-blocking shutdown, then SIGKILL each live worker). Use the stdlib method and drop the helper and its test.
Read the env override with a default of 4 and clamp the result instead of branching on whether the override is set.
The parallel path cannot use it (LIEF objects do not pickle and forkserver workers do not inherit parent state), which left it as dead weight the parent had to clear by hand. Only single-binary apps and the workers=1 override still read it, and there the cost is one extra parse per dSYM binary. Remove it and let every path parse on demand.
Drop the in-process fallback for a single binary or workers=1. A one-worker pool costs about half a second to start under forkserver, which is noise against any binary's analysis, and one code path is easier to reason about than two. The env override remains as a plain worker-count knob.
Setting LAUNCHPAD_BINARY_ANALYSIS_WORKERS=0 runs binary analysis in the task process with no subprocess layer at all, matching the pre-parallel behavior. This gives ops a kill switch that removes the process pool entirely rather than just shrinking it to one worker.
Pool workers start with a bare interpreter, so their log records were dropped and the parent had to log on their behalf: a burst of started lines before the pool and a burst of completed lines after it. Give each worker a QueueHandler and drain the queue in the parent, re-emitting records through its own handlers with the parent's request id attached. The per-binary started and completed logs now fire inside the worker at the moment the work happens, and the parent-side logging loops are gone.
The relay stopped its drain thread by putting a sentinel on the queue from the parent. That first put starts a feeder thread which must take the queue's shared write lock, and a worker SIGKILLed while holding that lock would block the feeder forever; multiprocessing then joins it with no timeout at interpreter exit, hanging the task process. Stop the drain thread with an Event and a polling get instead, so the parent never writes and no feeder thread is ever started.
Pool workers have no Sentry client, so the span @sentry_sdk.trace put on _analyze_binary vanished from the task transaction on the parallel path. Have the worker return start and end timestamps with each result and open the equivalent span in the parent with those timestamps, so the transaction waterfall shows every binary and their real overlap. The in-process path still produces the decorator's own span.
Logger.handle skips the logger's own level check, so a worker's INFO records from third-party loggers such as lief sailed past the WARNING suppression setup_logging applies in the parent. Gate re-emission on isEnabledFor. Also isolate per-record failures so one undecodable record cannot stop the relay for the rest of the run, and warn if the drain thread fails to stop after the pool is torn down.
Keep elapsed_s on time.monotonic so a clock adjustment cannot skew it, and use a single wall-clock reading only to anchor the rebuilt Sentry span, deriving its end from the monotonic duration.
Prototype of the simpler design suggested in review. Pool workers inherit the task's stdout, so each worker configures its own logging with setup_logging, adopts the parent's request id, and initializes its own Sentry client with the parent's config, continuing the parent's trace from propagated headers. Worker logs reach GCP/Datadog via stdout and Sentry Logs via the worker's client, both under the build's trace, and the queue-based relay, its drain thread, and its teardown edge cases go away. Each worker flushes its client after every binary so a deadline kill loses at most the binary in flight.
Move the per-binary gc.collect into the shared wrapper so the pool path bounds memory like the in-process path, drop the LAUNCHPAD_ENV guard now that any launchpad-initialized Sentry client implies it is set, annotate extract_dir as the SafeDirectory it receives, hoist the default worker count to a constant, and fix wording left over from the LIEF cache removal. Fold the worker-count tests into one, drop two tests subsumed by the stdout and ingest tests, and assert workers emit no transactions.
8462c22 to
f3e6354
Compare
2 participants
The per-binary Mach-O analysis loop ran serially and dominated wall-clock time on a large anonymized iOS app (hundreds of binaries) — a major contributor to hitting the 15-minute deadline.
The work is CPU-bound Python (LIEF, symbol sizing, demangling), so this parallelizes it with a
ProcessPoolExecutorto get past the GIL (threads were tried first and regressed). Workers parse from disk and results stay in input order, sobinary_analysisand the treemap are unchanged. Worker count is a fixed4to match the pods' CPU request — prod sets no CPU limit, soos.cpu_count()would read node cores and oversubscribe — overridable viaLAUNCHPAD_BINARY_ANALYSIS_WORKERS, where0runs in-process with no pool at all (the rollback switch). Demangling runs serial inside workers to cap subprocess fan-out, and the LIEF pre-parse cache is removed since workers couldn't use it anyway.Workers start with a bare interpreter, so each configures its own logging and initializes its own Sentry client with the parent's config, continuing the parent's trace from propagated headers. Per-binary started/completed logs (with
elapsed_s) fire inside the worker at the moment of the work and reach both stdout and Sentry Logs under the build's trace. Workers also return start/end timestamps and the parent rebuilds the per-binary span from them, so the trace waterfall shows real overlap.Timeout safety was the main review concern, since a worker wedged in native LIEF ignores
SIGTERM. We traced how the taskbroker enforces the deadline: it's an in-processSIGALRMraisingProcessingDeadlineExceededinside the task process — there's no external kill. Because the main process is idle inexecutor.mapwhen it fires, ourexceptcallsexecutor.kill_workers()(new in 3.14), whichSIGKILLs the wedged workers directly (verified underforkserver, prod's start method). If the main process is hard-killed instead (e.g. OOM), it's the container's PID 1, so the runtime tears down the whole cgroup and takes the workers with it. Either way, no orphaned binary-analysis subprocesses.Benchmark — large anonymized app, 8 workers on a 10-core dev box (shipped default is 4, so real-world gain is a bit smaller):
Verified with in-process-vs-parallel equivalence, worker-count, worker-logging (stdout with request id, third-party suppression, and delivery to a local Sentry ingest stub under the parent's trace), and rebuilt-span tests.