1287221 - WebDriver:Navigate results in slower performance.timing metrics

Status: RESOLVED DUPLICATE of bug 1417308

(Remote Protocol :: Marionette, defect, P3)

Description

[Nolan Lawson]

Attachment: repro-geckodriver-perf-bug.zip

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/51.0.2704.79 Safari/537.36 Edge/14.14385

Steps to reproduce:

1. Start Selenium 2.53.1
2. Use geckodriver 0.9.0 to control Firefox 47.0.1 in Windows 10 (14385 Insider Preview)
3. Use geckodriver to navigate to a page
4. Wait 2 seconds
5. Use geckodriver to evaluate `performance.timing`


Actual results:

Timing results for `load` and `DOMContentLoaded` as reported by `performance.timing` are very frequently 100-1000 milliseconds slower than when doing the same action manually.


Expected results:

I would expect WebDriver not to impact the performance metrics of `performance.timing`. For both Chrome and Edge, we've found we're able to get numbers pretty consistent between manual testing and automated testing, but Firefox's numbers make navigation in Firefox seem much slower than it actually is.

To give you some examples, here are some load numbers for manually navigating to google.com (same machine, same size browser window, all browser history and cache cleared before starting, navigating by simply typing "google.com" into the address bar), vs with the automated tests (note that the first row is a clean navigation, subsequent ones are cached):

Firefox manual	Firefox geckodriver 0.9.0	Performance difference
547	1284	134.73%
339	895	164.01%
326	1243	281.29%
326	902	176.69%
342	909	165.79%

We've observed similar impacts for other websites, e.g. bing.com:

342	909	165.79%
376	532	41.49%
173	339	95.95%
179	405	126.26%
198	322	62.63%
346	367	6.07%

And mozilla.com:

1123	1435	27.78%
403	522	29.53%
440	564	28.18%
541	539	-0.37%
468	523	11.75%

I've attached a test case, which is a Node.js project that can be run in Node 4 and above. The README explains how to run it. Here's the repo: https://gist.github.com/nolanlawson/035ffe2708f9e2d2f8ead435815b2200

Note that we also tested with a C#-based Selenium client using the older non-Marionette WebDriver in Firefox 46.0.1 and saw similar results. Varying the sleep delay didn't change anything either. So it doesn't seem to be a bug in Selenium, geckodriver, or any other piece of the pipeline; rather it seems like a bug in Firefox's WebDriver implementation.

Comment 1

[James Graham [:jgraham]]

Using WebDriver is not a good way to do performance testing as it may require non-default codepaths in the browser to enable the additional exposed functionality. Also, in general, performance is not a hard requirement for WebDriver.

However in this specific case it may be worth our while profiling to understand where the slowdown comes from.

Comment 2

[Andreas Tolfsen ❲:ato❳]

I do wonder if we get the timers wrong for the page loading strategy in https://github.com/mozilla/gecko-dev/blob/master/testing/marionette/listener.js#L922 or some related function.  After the DOM event fires, we poll for the ready state of the content listener in case a remoteness change has occurred in https://github.com/mozilla/gecko-dev/blob/master/testing/marionette/driver.js#L977.

This isn’t the easiest code to understand or reason about. )-:

Comment 3

[James Graham [:jgraham]]

I don't think that should make a difference unless it somehow interferes with the navigation timing determination of when a page is done loading. Notice that this is not a "page takes too long until WebDriver'g Go command returns" bug, but a "according to the internal browser timer the page took longer to load when using WebDriver" bug.