1767068 - Significant slow-down in startup times for ASan builds since update to rustc 1.60 and Clang14

Status: NEW

(Core :: Sanitizers, defect)

Description

[Jason Kratzer [:jkratzer]]

Prior to bug 1758780 landing, ASan builds took approximately 12s to launch. After bug 1758780, the same builds take between 30 and 50s to start. Is this expected? Are there any specific features in these new versions that should cause such a significant slow-down?

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

:glandium, since you are the author of the regressor, bug 1758780, could you take a look?
For more information, please visit auto_nag documentation.

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1758780

Comment 3

[Mike Hommey [:glandium]]

I don't reproduce.

Comment 4

[Jason Kratzer [:jkratzer]]

We use grizzly to ensure that we're creating a new profile for each instance:

➜  pip install fuzzfetch grizzly-framework
➜  echo "<script>window.close()</script>" > testcase.html
➜  fuzzfetch -a --fuzzing --build 2022-04-01 -n pre-clang-14
[2022-05-04 11:34:05] Identified task: https://firefox-ci-tc.services.mozilla.com/api/index/v1/task/gecko.v2.mozilla-central.pushdate.2022.04.01.20220401092803.firefox.linux64-fuzzing-asan-opt
[2022-05-04 11:34:05] > Task ID: BkOSqQhaSLqkfjUvJyR_wg
[2022-05-04 11:34:05] > Rank: 1648805283
[2022-05-04 11:34:05] > Changeset: a9b419c8a9c8f73b7ae8f18ff13a92499b3a2fa4
[2022-05-04 11:34:05] > Build ID: 20220401092803
[2022-05-04 11:34:06] > Downloading: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BkOSqQhaSLqkfjUvJyR_wg/artifacts/public/build/target.tar.bz2 (437.15MiB total)
[2022-05-04 11:34:35] .. still downloading (98.1%, 14.99MB/s)
[2022-05-04 11:34:36] .. downloaded (15.00MB/s)
[2022-05-04 11:34:36] .. extracting
[2022-05-04 11:36:26] Extracted into /home/jkratzer/crashes/test/pre-clang-14
➜  python -m grizzly.replay --xvfb ./pre-clang-14/firefox ./testcase.html 
[2022-05-04 11:36:53] Starting Grizzly Replay
[2022-05-04 11:36:53] Ignoring: log-limit, timeout
[2022-05-04 11:36:53] Running with Xvfb
[2022-05-04 11:36:53] Using time limit: 30s, timeout: 45s
[2022-05-04 11:36:53] Repeat: 1, Minimum crashes: 1, Relaunch 1  # Attempting to launch browser
[2022-05-04 11:37:00] Running test (1/1)...
[2022-05-04 11:37:03] Failed to reproduce results
[2022-05-04 11:37:03] Shutting down...
[2022-05-04 11:37:03] Done.
➜  fuzzfetch -a --fuzzing -n post-clang-14
[2022-05-04 11:37:17] Identified task: https://firefox-ci-tc.services.mozilla.com/api/index/v1/task/gecko.v2.mozilla-central.latest.firefox.linux64-fuzzing-asan-opt
[2022-05-04 11:37:17] > Task ID: BevpuYcSSnucsEfr1kzLfg
[2022-05-04 11:37:17] > Rank: 1651657079
[2022-05-04 11:37:17] > Changeset: 1a63d68454d11cb0ed8b08e31ce00ad8d5eefddf
[2022-05-04 11:37:17] > Build ID: 20220504093759
[2022-05-04 11:37:17] > Downloading: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BevpuYcSSnucsEfr1kzLfg/artifacts/public/build/target.tar.bz2 (449.15MiB total)
[2022-05-04 11:37:46] .. downloaded (16.06MB/s)
[2022-05-04 11:37:46] .. extracting
[2022-05-04 11:39:41] Extracted into /home/jkratzer/crashes/test/post-clang-14
➜  python -m grizzly.replay --xvfb ./post-clang-14/firefox ./testcase.html
[2022-05-04 11:41:45] Starting Grizzly Replay
[2022-05-04 11:41:45] Ignoring: log-limit, timeout
[2022-05-04 11:41:45] Running with Xvfb
[2022-05-04 11:41:45] Using time limit: 30s, timeout: 45s
[2022-05-04 11:41:45] Repeat: 1, Minimum crashes: 1, Relaunch 1 # Attempting to launch browser
[2022-05-04 11:42:32] Running test (1/1)...
[2022-05-04 11:42:35] Failed to reproduce results
[2022-05-04 11:42:35] Shutting down...
[2022-05-04 11:42:35] Done.

Note the times between # Attempting to launch browser and Running test. This demonstrates the time difference (3s vs 47s).

Comment 5

[Jesse Schwartzentruber (:truber)]

This seems to be ubuntu specific. I'm putting together STR now using docker. I can't repro using debian 12 (wayland, xwayland, xvfb) nor arch linux (x11, xvfb) .. but I can repro on ubuntu 20.04 (x11, xvfb) only when ubuntu-desktop is installed.

Comment 6

[Jesse Schwartzentruber (:truber)]

Attachment: Dockerfile-firefox

Comment 7

[Jesse Schwartzentruber (:truber)]

Attachment: Dockerfile-desktop

Comment 8

[Jesse Schwartzentruber (:truber)]

STR (Dockerfiles for both are attached):

$ docker run --rm mozillasecurity/ubuntu:firefox
+ python3 -m fuzzfetch --fuzzing --asan -n firefox
[2022-05-20 17:14:58] Identified task: https://firefox-ci-tc.services.mozilla.com/api/index/v1/task/gecko.v2.mozilla-central.latest.firefox.linux64-fuzzing-asan-opt
[2022-05-20 17:14:58] > Task ID: WciOk0uFT3mTehwcTUBJ2g
[2022-05-20 17:14:58] > Rank: 1653061023
[2022-05-20 17:14:58] > Changeset: 1d31a009897964e94d43db5961ff68538d5e8ddb
[2022-05-20 17:14:58] > Build ID: 20220520153703
[2022-05-20 17:14:58] > Downloading: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WciOk0uFT3mTehwcTUBJ2g/artifacts/public/build/target.tar.bz2 (450.22MiB total)
[2022-05-20 17:15:09] .. downloaded (43.27MB/s)
[2022-05-20 17:15:09] .. extracting
[2022-05-20 17:15:29] Extracted into /home/worker/firefox
+ python3 -m grizzly.replay firefox/firefox testcase.html --xvfb
[2022-05-20 17:15:29] Starting Grizzly Replay
[2022-05-20 17:15:29] Ignoring: log-limit, timeout
[2022-05-20 17:15:29] Running with Xvfb
[2022-05-20 17:15:29] Using time limit: 30s, timeout: 45s
[2022-05-20 17:15:29] Repeat: 1, Minimum crashes: 1, Relaunch 1
[2022-05-20 17:15:41] Running test (1/1)...
[2022-05-20 17:15:47] Failed to reproduce results
[2022-05-20 17:15:47] Shutting down...
[2022-05-20 17:15:47] Done.

(time to launch: 12s)

$ docker run --rm mozillasecurity/ubuntu:desktop
+ python3 -m fuzzfetch --fuzzing --asan -n firefox
[2022-05-20 17:16:03] Identified task: https://firefox-ci-tc.services.mozilla.com/api/index/v1/task/gecko.v2.mozilla-central.latest.firefox.linux64-fuzzing-asan-opt
[2022-05-20 17:16:03] > Task ID: WciOk0uFT3mTehwcTUBJ2g
[2022-05-20 17:16:03] > Rank: 1653061023
[2022-05-20 17:16:03] > Changeset: 1d31a009897964e94d43db5961ff68538d5e8ddb
[2022-05-20 17:16:03] > Build ID: 20220520153703
[2022-05-20 17:16:04] > Downloading: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WciOk0uFT3mTehwcTUBJ2g/artifacts/public/build/target.tar.bz2 (450.22MiB total)
[2022-05-20 17:16:14] .. downloaded (43.63MB/s)
[2022-05-20 17:16:14] .. extracting
[2022-05-20 17:16:35] Extracted into /home/worker/firefox
+ python3 -m grizzly.replay firefox/firefox testcase.html --xvfb
[2022-05-20 17:16:35] Starting Grizzly Replay
[2022-05-20 17:16:35] Ignoring: log-limit, timeout
[2022-05-20 17:16:35] Running with Xvfb
[2022-05-20 17:16:35] Using time limit: 30s, timeout: 45s
[2022-05-20 17:16:35] Repeat: 1, Minimum crashes: 1, Relaunch 1
[2022-05-20 17:17:17] Running test (1/1)...
[2022-05-20 17:17:21] Failed to reproduce results
[2022-05-20 17:17:21] Shutting down...
[2022-05-20 17:17:21] Done.

(time to launch: 42s)

$ docker run --rm mozillasecurity/ubuntu:desktop bash -exc "python3 -m fuzzfetch --fuzzing --asan -n firefox --build 2022-04-01 && python3 -m grizzly.replay firefox/firefox testcase.html --xvfb"
+ python3 -m fuzzfetch --fuzzing --asan -n firefox --build 2022-04-01
[2022-05-20 17:17:49] Identified task: https://firefox-ci-tc.services.mozilla.com/api/index/v1/task/gecko.v2.mozilla-central.pushdate.2022.04.01.20220401092803.firefox.linux64-fuzzing-asan-opt
[2022-05-20 17:17:49] > Task ID: BkOSqQhaSLqkfjUvJyR_wg
[2022-05-20 17:17:49] > Rank: 1648805283
[2022-05-20 17:17:49] > Changeset: a9b419c8a9c8f73b7ae8f18ff13a92499b3a2fa4
[2022-05-20 17:17:49] > Build ID: 20220401092803
[2022-05-20 17:17:50] > Downloading: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/BkOSqQhaSLqkfjUvJyR_wg/artifacts/public/build/target.tar.bz2 (437.15MiB total)
[2022-05-20 17:18:02] .. downloaded (35.97MB/s)
[2022-05-20 17:18:02] .. extracting
[2022-05-20 17:18:21] Extracted into /home/worker/firefox
+ python3 -m grizzly.replay firefox/firefox testcase.html --xvfb
[2022-05-20 17:18:22] Starting Grizzly Replay
[2022-05-20 17:18:22] Ignoring: log-limit, timeout
[2022-05-20 17:18:22] Running with Xvfb
[2022-05-20 17:18:22] Using time limit: 30s, timeout: 45s
[2022-05-20 17:18:22] Repeat: 1, Minimum crashes: 1, Relaunch 1
[2022-05-20 17:18:34] Running test (1/1)...
[2022-05-20 17:18:40] Failed to reproduce results
[2022-05-20 17:18:40] Shutting down...
[2022-05-20 17:18:40] Done.

(time to launch: 12s)

So some ubuntu package installed by ubuntu-minimal-desktop but not a dependency of ubuntu's firefox package is causing a 30s asan startup slowdown since the clang 14 update.

Comment 9

[Jesse Schwartzentruber (:truber)]

Jason and I narrowed this down to yaru-theme-gtk (specifically, not its deps).

Comment 10

[Tyson Smith [:tsmith]]

ASAN_OPTIONS=strict_string_checks=true seems to be the source of the issue. It is set to true by FFPuppet which explains why we are seeing it in automation.

Comment 11

[BugBot [:suhaib / :marco/ :calixte]]

The severity field is not set for this bug.
:decoder, could you have a look please?

For more information, please visit auto_nag documentation.