To close the loop - thanks to the feedback (i.e. pointing out that the CL causes a broad slowdown) I was able to identify the root problem: some low-level, performance-sensitive pieces of Rust standard library were getting instrumented for code coverage - see https://crbug.com/395690207 for more details.
Thank you for your help! On Mon, Feb 10, 2025 at 1:11 PM Weizhong Xia <weizh...@google.com> wrote: > yeah, let's continue our discussion through the bug. > > On Mon, Feb 10, 2025 at 12:12 PM Łukasz Anforowicz <luka...@chromium.org> > wrote: > >> Ooops... it seems that I've sent my reply before noticing your comment on >> the bug from a few minutes ago. I'll take a look. >> >> On Mon, Feb 10, 2025 at 12:10 PM Łukasz Anforowicz <luka...@chromium.org> >> wrote: >> >>> On Mon, Feb 10, 2025 at 11:01 AM Weizhong Xia <weizh...@google.com> >>> wrote: >>> >>>> Looking into the log I see a lot of tests timed out. Maybe that is the >>>> reason why the total test time increased a lot. >>>> >>> >>> Just to double-check: *Have you also looked at mac-rel >>> <https://ci.chromium.org/ui/p/chromium/builders/try/mac-rel/2079605/overview> >>> step >>> 164 ("headless_shell_wpt_tests (without patch) on Mac-14") which is red >>> *without* my patch?* Is it also red because of test timeouts? FWIW I >>> see that stdout >>> <https://logs.chromium.org/logs/chromium/buildbucket/cr-buildbucket/8723633334109810449/+/u/headless_shell_wpt_tests__without_patch__on_Mac-14/stdout> >>> of this step reports only 2 timeouts: >>> >>> $ cat stdout | grep TIMEOUT.*expected >>> ▶ TIMEOUT [expected OK] >>> external/wpt/svg/interact/scripted/focus-events.svg >>> ▶ TIMEOUT [expected OK] >>> external/wpt/compute-pressure/compute_pressure_disconnect_idempotent.https.window.html?globalScope=window >>> >>> >>> >>>> Can you check if your change has slowed down the test? I see on mac-rel >>>> the total test time for headless_shell_wpt_tests is 352 min, while the P50 >>>> now is 190 min. This is similarly true for linux-rel and win-rel. >>>> >>> >>> *There are indeed some timeouts, but much less than the "1450 failures"* >>> reported at the top of the mac-rel results. In stdout >>> <https://logs.chromium.org/logs/chromium/buildbucket/cr-buildbucket/8723633334109810449/+/u/headless_shell_wpt_tests__with_patch__on_Mac-14/stdout?format=raw> >>> of step 130 I see 133 timeouts: >>> >>> $ cat stdout\?format\=raw | grep TIMEOUT.*expected | wc -l >>> grep: (standard input): binary file matches >>> >>> >>> *I expect that my CL will have some impact on performance of PNG >>> decoding and encoding.* Looking at the (Google-internal link) >>> Finch/UMA dashboard at >>> https://uma.googleplex.com/p/chrome/variations?sid=d8ca164209cfbd8c7cff6fd2574a03bb, >>> I indeed see some slowdown in PNG decoding speed as reported by >>> Renderer4.ImageDecodeTaskDurationUs.Png.Software and >>> ImageDecoder.Png.UiGfxIntoSkBitmap. The encoding speed seems to be neutral >>> or improved as reported by Blink.Canvas.ToDataURLScaledDuration.PNG and >>> Blink.Canvas.ToBlob.TotalEncodingDelay.PNG. OTOH, so far I have not been >>> able to reproduce the same magnitude of the slowdown in local decoding >>> benchmarks - see >>> https://docs.google.com/document/d/12gj3dnGyc9ZPvsu-53gTN38WneOnF_QddJ5WvsiizXg/edit?usp=sharing >>> >>> *Nevertheless, I do *not* expect my CL to almost double the test time*. >>> The PNG decoding and encoding slowdown I observed in Canary trials has been >>> surprisingly high, but it still shouldn't cause such a dramatic increase in >>> test time, because I expect that PNG decoding/encoding time should be a >>> small percentage of the total test runtime (at least for most tests). >>> >>> *I cannot repro the timeouts locally. *For example, win-rel >>> <https://ci.chromium.org/ui/p/chromium/builders/try/win-rel/907626/overview> >>> reported >>> <https://chromium-layout-test-archives.storage.googleapis.com/results.html?json=chromium/try/win-rel/907626/headless_shell_wpt_tests%20%28with%20patch%29/full_results_jsonp.js> >>> a timeout in external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html; >>> and stdout >>> <https://logs.chromium.org/logs/chromium/buildbucket/cr-buildbucket/8723633334109810449/+/u/headless_shell_wpt_tests__with_patch__on_Mac-14/stdout> >>> of step 130 of the massively-failing mac-rel >>> <https://ci.chromium.org/ui/p/chromium/builders/try/mac-rel/2079605/overview> >>> seems to report a timeout >>> of >>> virtual/scalefactor200/external/wpt/css/css-backgrounds/hidpi/simple-bg-color.html. >>> And I can't repro the timeout in the first test on my gWindows CloudTop (I >>> tried the second test on my gLinux CloudTop - not quite matching the bot >>> setup but I don't have a Mac to test with.) I also tried to measure the >>> test duration on gWindows CloudTop with and without enabling my feature (I >>> used `run_web_tests.bat`, because I didn't find an equivalent of `--timing` >>> flag in the output of `run_wpt_tests.bat --help`) - the feature doesn't >>> seem to have a big effect on the test runtime: >>> >>> With my feature the average test runtime is 0.68712s: >>> >>> C:\src\chromium\src>third_party\blink\tools\run_web_tests.bat -t rel >>> external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> --iterations=10 --timing --verbose >>> ... >>> [1/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.7871s >>> [2/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6953s >>> [3/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6670s >>> [4/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6659s >>> [5/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6802s >>> [6/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6816s >>> [7/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6650s >>> [8/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6680s >>> [9/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6823s >>> [10/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6788s >>> Finally stop servers and clean up >>> >>> All 10 tests ran as expected in 50.72s (49.42s in rwt, 1x). >>> >>> >>> Without my feature (misspelling the `enabled_features` entry in >>> `fieldtrial_testing_config.json` and recompiling via `autoninja -C out\rel >>> blink_tests`) the average runtime is 0.6703s: >>> >>> C:\src\chromium\src>third_party\blink\tools\run_web_tests.bat -t rel >>> external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> --iterations=10 --timing --verbose >>> ... >>> [1/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6939s >>> [2/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6660s >>> [3/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6523s >>> [4/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6504s >>> [5/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.7513s >>> [6/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6651s >>> [7/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6514s >>> [8/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6489s >>> [9/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6636s >>> [10/10] external/wpt/css/geometry/DOMMatrix2DInit-validate-fixup.html >>> passed 0.6601s >>> Finally stop servers and clean up >>> >>> All 10 tests ran as expected in 50.43s (49.13s in rwt, 1x). >>> >>> >>>> >>>> Please always feel free to reach out if you need help, :-). >>>> >>> >>> Thanks for taking a look! >>> >>>> >>>> thanks, Weizhong >>>> >>>> >>>> >>>> On Mon, Feb 10, 2025 at 10:06 AM Xianzhu Wang <wangxian...@chromium.org> >>>> wrote: >>>> >>>>> I believe this is an infra issue. I've moved the bug to Blink>Infra. >>>>> >>>>> On Mon, Feb 10, 2025 at 9:14 AM Łukasz Anforowicz < >>>>> luka...@chromium.org> wrote: >>>>> >>>>>> Hello @blink-dev, >>>>>> >>>>>> I would appreciate help with understanding why >>>>>> `headless_shell_wpt_tests` step is red in my tryjobs (presumably because >>>>>> of >>>>>> my CL which enables Rust PNG via `fieldtrial_testing_config.json`?). In >>>>>> https://crbug.com/395446442 I link to an example where `mac-rel` is >>>>>> red, and says things like "result unexpectedly crashed" or "1450 >>>>>> failures", >>>>>> but I am unable to find test logs that would show a callstack of a crash, >>>>>> or a specific test assertion that fails. >>>>>> >>>>>> Did I miss something when looking at the tryjob results? Maybe I >>>>>> should ask the infra team for help with this? >>>>>> >>>>>> Best regards, >>>>>> >>>>>> Lukasz >>>>>> >>>>>> -- >>>>>> You received this message because you are subscribed to the Google >>>>>> Groups "blink-dev" group. >>>>>> To unsubscribe from this group and stop receiving emails from it, >>>>>> send an email to blink-dev+unsubscr...@chromium.org. >>>>>> To view this discussion visit >>>>>> https://groups.google.com/a/chromium.org/d/msgid/blink-dev/CAA_NCUFV7MgpXgK9PgaNFBrFtqBNYAGeYWf7F3t3-iAjhCrb9w%40mail.gmail.com >>>>>> <https://groups.google.com/a/chromium.org/d/msgid/blink-dev/CAA_NCUFV7MgpXgK9PgaNFBrFtqBNYAGeYWf7F3t3-iAjhCrb9w%40mail.gmail.com?utm_medium=email&utm_source=footer> >>>>>> . >>>>>> >>>>> -- You received this message because you are subscribed to the Google Groups "blink-dev" group. To unsubscribe from this group and stop receiving emails from it, send an email to blink-dev+unsubscr...@chromium.org. To view this discussion visit https://groups.google.com/a/chromium.org/d/msgid/blink-dev/CAA_NCUEXoe4_j1G-7r197f6gmRA3_r7Kx3Ut5HdtJE5DSkCqvw%40mail.gmail.com.
