1887646 - [meta] Build / package / install loop is significantly slower than it should be

Status: NEW

(Firefox Build System :: Android Studio and Gradle Integration, defect, P1)

Description

[Paul Adenot (:padenot)]

This results in a very bad regression for local development. On almost the fastest Linux machine, money can buy currently, a no-op mach build && mach package && mach install is 3min09.

A desktop clobber build on that machine is 4min. A no-op build on that machine is 5-10s.

Comment 1

[Johan Lorenzo [:jlorenzo]]

Hey :rsainani! Would be aware of any recent change in the way Geckoview example is built? Per :florian, the regression happened sometime last week.

Comment 2

[Johan Lorenzo [:jlorenzo]]

I'd like to clarify my last message. We're not 100% clear whether bug 1822248 is the root cause. :padenot believe it was. :florian was on top of [1] (right after the merge) and it ran in ~35s. If there's any other recent change in the build pipeline, let's call them out. Otherwise, a bisection would be good.

[1] https://hg.mozilla.org/mozilla-central/rev/e427f093926a

Comment 3

[Florian Quèze [:florian]]

(In reply to Johan Lorenzo [:jlorenzo] from comment #2)

:florian was on top of [1] (right after the merge) and it ran in ~35s.

[1] https://hg.mozilla.org/mozilla-central/rev/e427f093926a

I updated to that revision again to verify, and that revision was already slow (2min58s to run mach run).

Comment 4

[Florian Quèze [:florian]]

(In reply to Florian Quèze [:florian] from comment #3)

(In reply to Johan Lorenzo [:jlorenzo] from comment #2)

:florian was on top of [1] (right after the merge) and it ran in ~35s.

[1] https://hg.mozilla.org/mozilla-central/rev/e427f093926a

I updated to that revision again to verify, and that revision was already slow (2min58s to run mach run).

I now updated to the older 7af568614e1e revision, and a no-op mach build took 22s, and mach run took 33s.

Comment 5

[Johan Lorenzo [:jlorenzo]]

(In reply to Florian Quèze [:florian] from comment #4)

I now updated to the older 7af568614e1e revision, and a no-op mach build took 22s, and mach run took 33s.

Thanks for the confirmation, :florian!

Comment 6

[:gerard-majax]

git pull on my desktop to rebase android patches, and 3min 40sec running some configure steps before the actual build started. Pure mach build. The actual build thus started at 3:40, finished at 7:40 but overall process took 9min. It's mostly half of the time doing not much :(

Comment 7

[Nick Alexander :nalexander [he/him]]

Could I get a ./mach build -v -j1, which should have timestamps? We can figure out how to drive the Gradle logging up too, should we need to. Thanks!

Comment 8

[Julien Cristau [:jcristau]]

Attachment: no-op mach build log

Here's a log from a no-op mach build, that takes 30+ seconds.

Comment 9

[Nick Alexander :nalexander [he/him]]

(In reply to Julien Cristau [:jcristau] from comment #8)

Created attachment 9393462 [details]
no-op mach build log

Here's a log from a no-op mach build, that takes 30+ seconds.

Thanks Julien. Looks like the Gradle Glean integration is slow; depending on the shape of the inputs and outputs we might be able to improve that. I can't look any time soon but hopefully we can loop in the Glean folks who know the Gradle integration and see if we can drive that down.

We may also be eating the reality of Gradle configuring N projects. That can make Gradle do a great deal of work; we might need to use the newer, more dynamic, configuration methods to avoid that. I am not familiar with the details -- those came into vogue as I was exiting day-to-day Gradle work -- but hopefully Gabriel and Titouan can assist.

Comment 10

[Gabriel Luong [:gl] (ΦωΦ)]

Assigning myself to begin investigating. Possible inspiration https://docs.gradle.org/current/userguide/task_configuration_avoidance.html

Comment 11

[Gabriel Luong [:gl] (ΦωΦ)]

@padenot which mozconfig are you using to build here? is this building GeckoView with Artifact builds?

Comment 12

[Paul Adenot (:padenot)]

Here's my mozconfig:

ac_add_options --enable-project=mobile/android
ac_add_options --target=x86_64 --enable-debug --enable-profiling

I was doing only no-op builds, because I was iterating on fixing tests for https://bugzilla.mozilla.org/show_bug.cgi?id=1860492, there was no change to build system files, code or anything like that, there was however changes to mochitest.toml files, and html files for mochitests.

Comment 13

[Joe M [:jmahon]]

Status update: still early in investigation. We still want to prioritize this highly but it's not technically a blocker for shipping 125 so we're moving it to Bug 1875511

Comment 14

[Gabriel Luong [:gl] (ΦωΦ)]

@padenot @florian Would you be able to provide me your logs of a mach run? In addition, if one of you could reproduce a log with a prior revision before the monorepo migration, that would be also valuable, but might not be necessary if (2) is performed.

Some additional inquires:
(1) Based on your prior experiences, how long did it take to perform a no-op mach build? I know from the previous comments we are looking at ~3minutes (post migration) vs 22-30s (before). However, I am asking again to re-confirm overall expectations of what the baseline looks like.
(2) From my own testing on my M1 Mac, it took me roughly ~1min to perform a mach run. If I excluded all the Fenix gradle configurations, I was able to get this back down to a range from 15-33s. The fluctuation in the range is kinda giving me pause because I simply don't what to expect with this workflow. I am looking for as much information I can get my hands on given that I cannot easily reproduce the ~3min build timing due to the difference in machines. I am gonna attach a patch (0001-Bug-1887646.patch) that will comment out as much of the Fenix gradle configurations. If y'all could apply the patch and give that a test to help see the build times are back to normal, that would be greatly appreciated. If the patch works out, then we can work towards ensuring we don't hit certain codepaths when running GV in an emulator via mach run.

Comment 15

[Gabriel Luong [:gl] (ΦωΦ)]

Attachment: 0001-Bug-1887646.patch

Comment 16

[Florian Quèze [:florian]]

Attachment: Log of a no-op mach run

I've just updated my mozilla-central tree, ran mach build, then mach run, then mach run a second time (I'm attaching the log of this second no-op mach run).

This is geckoview example, and I'm not using an emulator, a real Pixel 6 is connected through adb.

Comment 17

[Paul Adenot (:padenot)]

Attachment: mach-run.log

Attached are logs from mach run with everything built beforehand, recent revision, using an emulator on a very powerful machine. It's about 1:08 (I ran it multiple times).

Doing a trivial change in C++ code results in a 1:21 rebuild time (./mach build). Doing a ./mach run right after having built this change in C++ also results in a 1:08 time. For comparison, on this desktop, rebuilding is 12 seconds and running is more or less instant.

So something has certainly improved.

Applying the patch, building no-op (not a single change) is 1:06. Running is now 0:21 which is nicer, but we need to remember that all this is no-op and it should be reasonably instantaneous.

Comment 18

[Florian Quèze [:florian]]

Attachment: Log of a no-op mach build

Because there was a single mach invocation here (unlike mach run which does multiple sub invocations of mach), mach resource-use produces a profile that matches the total time mach build took, so I'm sharing it here: https://share.firefox.dev/3PZdNa2

Comment 19

[Florian Quèze [:florian]]

With attachment 9395924 [details] [diff] [review] applied, no-op mach run is down to 20s and no-op mach build is between 17 and 19s on my machine (M1 Max macbook pro).

Given I'm not using an emulator, I would say the expected behavior would be for mach run to take about 3s (the time it takes to transfer the data to the phone over USB). With an emulator, I would expect a no-op mach run to be just the time it takes to start Firefox.

Looking at the profile of the no-op mach build I shared in comment 18, it looks like there's about 2s of platform stuff, and at least 30s (maybe 35s) of Android specific stuff.

Comment 20

[Florian Quèze [:florian]]

With the patches from bug 1892641 (adding markers for gradle) landed and bug 1894285 (adding markers showing the processes that are running during a build) currently in review, we can see how most the time is spent.

Here's a profile of a full Android build on try: https://share.firefox.dev/3QqTEtD
And a profile of a no-op mach build locally: https://share.firefox.dev/3JFYY8C

I propose we change this bug to a meta bug and I will file blocking bugs for actionable things we can see in these profiles.

Comment 21

[Nazım Can Altınova [:canova]]

This bug is mostly about no-op mach build runs but I was also surprised by the build time differences of the full clobber builds so I think it might make sense to post the resource usage profiles in case it helps.

I got a new powerful desktop and was testing the build times. mozilla-central desktop clobber build takes 3mins 56secs, but android clobber build takes 9mins 39secs.

Desktop build resource usage profile: https://share.firefox.dev/3zFuD8B
Android build resource usage profile: https://share.firefox.dev/3WjHPsq
Second (no-op) android build resource usage profile (1min 10secs): https://share.firefox.dev/3xTxHgP
Third (no-op) android build resource usage profile (1min 9secs): https://share.firefox.dev/3S79fiF

Desktop build spends a lot of time utilizing most of the (64) cores. On the other hand, android full build spends a lot of time (around 4 mins) on the export/generate-generated-jni-wrappers phase, utilizing very few cores.