1592311 - [meta] Browser chrome tests execute very slowly

Status: RESOLVED WORKSFORME

(Remote Protocol :: Agent, task)

Description

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Currently it's a pain to run the browser chrome tests for the remote protocol because it's painful slow. The slowness comes all from the setup routine. Here some timing details:

1572361532984: before get cdp
1572361534490: after get cdp
1572361534490: before opening tab
1572361534490: after opening tab
1572361534490: before getting the client
1572361535452: after getting the client

As you can see both calls to await getCDP() and await CDP({ ... }) are actually causing this.

Within getCDP() it actually is the loading of the gigantic chrome-remote-interface.js script file. It takes about 1s on my local machine. For what exactly is this file needed? Maybe we cache the hidden window and keep it open as long as the browser stays open? Right now we seem to close it after each and every test.

I also tried to find the bottle neck for getting the client, but that seems to be harder and somewhere in that gigantic script.

Andreas, maybe you can shed some lights on it? Thanks!

Comment 1

[Andreas Tolfsen ❲:ato❳]

I don’t see any noteworthy slowdown on Linux,
where ./mach test --headless remote/test/browser/ runs in about 1m46.220s.

But I think your theory that loading chrome-remote-interface.js
each time in a new hidden window is one likely penalty, especially
considering the file size:

% du -sh remote/test/browser/chrome-remote-interface.js
864K	remote/test/browser/chrome-remote-interface.js

whimboo and I spent some time talking about this problem this
morning, and it would be worth investigating if we could increase
the lifetime of the hidden window the CDP client is loaded in.

Comment 2

[Henrik Skupin [:whimboo][⌚️UTC+1]]

So on MacOS it's much worse, and it doesn't actually depend on if I run the tests in headless mode or normal. Here the results for both:

headless: 285.85s user 24.07s system 137% cpu 3:45.06 total
normal: 296.20s user 27.70s system 138% cpu 3:53.26 total

Andreas, would you mind to prove that by running the tests on your MacBook with Catalina installed on? Having one more sample to know that it is slow would be great.

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+1]]

I will make this a meta bug given that multiple patches might be needed here. Caching the CDP client code would be one first good step we should look into soon.

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+1]]

I run the unit tests for the chrome-remote-interface client (./scripts/run-tests.sh) and our performance in connecting and closing a connection is very poor:

  closing a connection
    with callback
      ✓ should allow a subsequent new connection (1676ms)
    without callback
      ✓ should allow a subsequent new connection (1608ms)

  connecting to Chrome
    with callback
      with default parameters
        ✓ should succeed with "connect" callback passed as an argument (781ms)
      with custom parameters
        ✓ should succeed with "connect" callback passed as an argument (925ms)
        ✓ should succeed with custom target by index (773ms)
        ✓ should succeed with custom target by function (793ms)
        ✓ should succeed with custom target by object (783ms)
        ✓ should succeed with custom target by full URL (779ms)
        ✓ should succeed with custom target by partial URL (776ms)

With Chrome no timings are printed given that it is that fast.

This all might come down to our implementation of the Remote Agent and how we handle connecting and disconnecting. I'm going to file a new bug to improve the performance of both methods.

Comment 5

[Andreas Tolfsen ❲:ato❳]

(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #2)

Andreas, would you mind to prove that by running the tests on your MacBook with Catalina installed on? Having one more sample to know that it is slow would be great.

Sorry, I’m unable to get a development environment set up on macOS because ./mach bootstrap fails which means I can’t (easily) give you a metric on Catalina.

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+1]]

That's fine. Meanwhile we know where the problem is, and as such we would first need some progress on bug 1597227. Hopefully this will happen soon.

Comment 7

[Andreas Tolfsen ❲:ato❳]

I had to spend a whole lot of time getting Homebrew set up in order to provide some feedback on the bootstrapping bug I referred to in comment #5 (see bug 1602411 for details). This meant I somewhat accidentally had a working artifact build environment, so I was after all able to run the tests locally.

Of course we should be aware that as time goes on and more tests are added, the results posted to this bug will not be possible to compare. For that reason I’ve included timings also from Linux on the same revision checkout (666b11c33).

Making sure the test regeneration was done prior to the test runs, I got the following results:

macOS Catalina

opt

headless

real	2m48.558s
user	2m54.483s
sys	0m38.804s

windowed

real	3m3.350s
user	3m16.708s
sys	0m49.751s

debug

headless

real	9m41.769s
user	10m58.436s
sys	0m58.051s

windowed

real	8m36.427s
user	10m44.254s
sys	1m1.703s

Debian Linux stable

opt

headless

real	2m19.927s
user	2m31.906s
sys	0m30.154s

xvfb

real	3m48.528s
user	2m54.908s
sys	0m35.678s

debug

headless

real	7m10.951s
user	9m40.105s
sys	0m41.576s

xvfb

real	10m12.906s
user	10m38.925s
sys	0m45.565s

The Linux box doesn’t have a real display, so I went with Xvfb(1). I noticed that some tests fail in this mode so it might affect the figures.

Comment 8

[Henrik Skupin [:whimboo][⌚️UTC+1]]

This doesn't seem to be a problem anymore.