Andrew Grieve | 583e7b060 | 2022-10-28 19:31:36 | [diff] [blame] | 1 | # Debugging Slow Builds |
Andrew Grieve | bd10a66 | 2018-09-14 01:19:59 | [diff] [blame] | 2 | |
Andrew Grieve | 583e7b060 | 2022-10-28 19:31:36 | [diff] [blame] | 3 | Did you know that Ninja writes a log to disk after each build? |
| 4 | |
| 5 | To see what kinds of files took the longest for your previous build: |
| 6 | |
| 7 | ```sh |
| 8 | cd out/Default |
| 9 | # Lives in depot_tools: |
| 10 | post_build_ninja_summary.py |
| 11 | ``` |
| 12 | |
Bruce Dawson | d76e681 | 2023-08-09 16:48:03 | [diff] [blame] | 13 | Because the build is highly parallelized the `elapsed time` values are usually |
| 14 | not meaningful so the `weighted time` numbers are calculated to approximate |
| 15 | the impact of build steps on wall-clock time. |
| 16 | |
Andrew Grieve | 583e7b060 | 2022-10-28 19:31:36 | [diff] [blame] | 17 | You can also set `NINJA_SUMMARIZE_BUILD=1` to have this command run |
Bruce Dawson | d76e681 | 2023-08-09 16:48:03 | [diff] [blame] | 18 | after each `autoninja` invocation. Setting this environment variable also runs |
| 19 | ninja with `-d stats` which causes it to print out internal information such |
| 20 | as StartEdge times, which measures the times to create processes, and it |
| 21 | modifies the `NINJA_STATUS` environment variable to add information such as how |
| 22 | many processes are running at any given time - both are useful for detecting |
| 23 | slow process creation. You can get this last benefit on its own by setting |
| 24 | `NINJA_STATUS=[%r processes, %f/%t @ %o/s : %es ] ` (trailing space is |
| 25 | intentional). |
Andrew Grieve | 583e7b060 | 2022-10-28 19:31:36 | [diff] [blame] | 26 | |
| 27 | To generate a Chrome trace of your most recent build: |
| 28 | |
| 29 | ```sh |
| 30 | git clone https://github.com/nico/ninjatracing |
| 31 | ninjatracing/ninjatracing out/Default/.ninja_log > trace.json |
| 32 | # Then open in https://ui.perfetto.dev/ |
| 33 | ``` |
| 34 | |
Bruce Dawson | d76e681 | 2023-08-09 16:48:03 | [diff] [blame] | 35 | If your build is stuck on a long-running build step you can see what it is by |
| 36 | running `tools/buildstate.py`. |
| 37 | |
Andrew Grieve | 583e7b060 | 2022-10-28 19:31:36 | [diff] [blame] | 38 | ## Slow Bot Builds |
| 39 | |
| 40 | Our bots run `ninjatracing` and `post_build_ninja_summary.py` as well. |
| 41 | |
Bruce Dawson | d76e681 | 2023-08-09 16:48:03 | [diff] [blame] | 42 | Find the trace at: `postprocess for reclient > gsutil upload ninja_log > ninja_log`: |
Andrew Grieve | 583e7b060 | 2022-10-28 19:31:36 | [diff] [blame] | 43 | |
| 44 | * _".ninja_log in table format (full)"_ is for `post_build_ninja_summary.py`. |
| 45 | * _"trace viewer (sort_by_end)"_ is for `ninjatracing`. |
| 46 | |
| 47 | ## Advanced(ish) Tips |
| 48 | |
| 49 | * Use `gn gen --tracelog trace.json` to create a trace for `gn gen`. |
Andrew Grieve | bd10a66 | 2018-09-14 01:19:59 | [diff] [blame] | 50 | * Many Android templates make use of |
| 51 | [`md5_check.py`](https://cs.chromium.org/chromium/src/build/android/gyp/util/md5_check.py) |
| 52 | to optimize incremental builds. |
| 53 | * Set `PRINT_BUILD_EXPLANATIONS=1` to have these commands log which inputs |
| 54 | changed. |
| 55 | * If you suspect files are being rebuilt unnecessarily during incremental |
| 56 | builds: |
| 57 | * Use `ninja -n -d explain` to figure out why ninja thinks a target is dirty. |
| 58 | * Ensure actions are taking advantage of ninja's `restat=1` feature by not |
Andrew Grieve | 583e7b060 | 2022-10-28 19:31:36 | [diff] [blame] | 59 | updating timestamps on outputs when their contents do not change. |
| 60 | * E.g. by using [`build_utils.AtomicOutput()`] |
| 61 | |
| 62 | [`build_utils.AtomicOutput()`]: https://source.chromium.org/search?q=symbol:AtomicOutput%20f:build |