1585013 - Add gecko profiling support to raptor-browsertime (desktop)

Status: RESOLVED FIXED

(Testing :: Raptor, enhancement, P1)

Description

[Robert Wood [:rwood]]

Add the ability to generate gecko profiles while running raptor-browsertime tests. Start with page-load tests on desktop.

Comment 2

[Nick Alexander :nalexander [he/him]]

This will depend on https://github.com/mozilla/browsertime/issues/42, at least for warmload.

Comment 3

[Nick Alexander :nalexander [he/him]]

I have significant work in progress on this, but it's not quite all together yet. It's best to do this after merging upstream into mozilla/browsertime, which is a big lift (but done locally); and then I ran into some issues testing. Specifically, I'm not quite able to verify that we stitch visual metrics into profiles correctly after my changes, mostly 'cuz it took some time to discover the Gecko profiler needs an x86_64 build (and not an i686 build, see Bug 1580999) and then not yet being able to use the Gecko window recorder under the x86_64 emulator (see Bug 1584659).

I'll pick this up next week.

Comment 4

[Florin Strugariu [:Bebe]]

Attachment: Bug 1585013 - Add gecko profiling support to raptor-browsertime

Comment 5

[Florin Strugariu [:Bebe]]

the current patch adds the '--firefox.geckoProfiler' to the command line.

Browsertime fails with:

[task 2019-10-30T14:59:10.785Z] 14:59:10     INFO -  [2019-10-30 14:59:10] VERBOSE: [browsertime] Executing privileged async script Collect GeckoProfiler
[task 2019-10-30T14:59:10.819Z] 14:59:10     INFO -  /Users/cltbld/tasks/task_1572447399/fetches/browsertime/node_modules/browsertime/node_modules/selenium-webdriver/lib/promise.js:2626
[task 2019-10-30T14:59:10.819Z] 14:59:10     INFO -          throw error;
[task 2019-10-30T14:59:10.819Z] 14:59:10     INFO -          ^
[task 2019-10-30T14:59:10.819Z] 14:59:10     INFO -  JavascriptError: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIProfiler.dumpProfileToFileAsync]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: [System Principal] :: <TOP_LEVEL> :: line 4"  data: no]
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at Object.throwDecodedError (/Users/cltbld/tasks/task_1572447399/fetches/browsertime/node_modules/browsertime/node_modules/selenium-webdriver/lib/error.js:514:15)
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at parseHttpResponse (/Users/cltbld/tasks/task_1572447399/fetches/browsertime/node_modules/browsertime/node_modules/selenium-webdriver/lib/http.js:519:13)
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at doSend.then.response (/Users/cltbld/tasks/task_1572447399/fetches/browsertime/node_modules/browsertime/node_modules/selenium-webdriver/lib/http.js:441:30)
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at <anonymous>
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at process._tickCallback (internal/process/next_tick.js:188:7)
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -  From: Task: WebDriver.executeScript()
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at Driver.schedule (/Users/cltbld/tasks/task_1572447399/fetches/browsertime/node_modules/browsertime/node_modules/selenium-webdriver/lib/webdriver.js:807:17)
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at Driver.executeAsyncScript (/Users/cltbld/tasks/task_1572447399/fetches/browsertime/node_modules/browsertime/node_modules/selenium-webdriver/lib/webdriver.js:891:17)
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at SeleniumRunner.runPrivilegedAsyncScript (/Users/cltbld/tasks/task_1572447399/fetches/browsertime/node_modules/browsertime/lib/core/seleniumRunner.js:386:30)
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at <anonymous>
[task 2019-10-30T14:59:10.820Z] 14:59:10     INFO -      at process._tickCallback (internal/process/next_tick.js:188:7)
[task 2019-10-30T15:01:11.088Z] 15:01:11    ERROR -  Traceback (most recent call last):
[task 2019-10-30T15:01:11.088Z] 15:01:11     INFO -    File "/Users/cltbld/tasks/task_1572447399/build/tests/raptor/raptor/raptor.py", line 1532, in <module>
[task 2019-10-30T15:01:11.088Z] 15:01:11     INFO -      main()
[task 2019-10-30T15:01:11.088Z] 15:01:11     INFO -    File "/Users/cltbld/tasks/task_1572447399/build/tests/raptor/raptor/raptor.py", line 1500, in main
[task 2019-10-30T15:01:11.088Z] 15:01:11     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2019-10-30T15:01:11.088Z] 15:01:11     INFO -    File "/Users/cltbld/tasks/task_1572447399/build/tests/raptor/raptor/raptor.py", line 213, in run_tests
[task 2019-10-30T15:01:11.089Z] 15:01:11     INFO -      self.run_test_teardown(test)
[task 2019-10-30T15:01:11.089Z] 15:01:11     INFO -    File "/Users/cltbld/tasks/task_1572447399/build/tests/raptor/raptor/raptor.py", line 406, in run_test_teardown
[task 2019-10-30T15:01:11.089Z] 15:01:11     INFO -      super(Browsertime, self).run_test_teardown(test)
[task 2019-10-30T15:01:11.089Z] 15:01:11     INFO -    File "/Users/cltbld/tasks/task_1572447399/build/tests/raptor/raptor/raptor.py", line 228, in run_test_teardown
[task 2019-10-30T15:01:11.089Z] 15:01:11     INFO -      self.gecko_profiler.symbolicate()
[task 2019-10-30T15:01:11.089Z] 15:01:11     INFO -  AttributeError: 'NoneType' object has no attribute 'symbolicate'
[task 2019-10-30T15:01:11.243Z] 15:01:11    ERROR - Return code: 1
[task 2019-10-30T15:01:11.243Z] 15:01:11  WARNING - setting return code to 1
[task 2019-10-30T15:01:11.243Z] 15:01:11     INFO - Copying Raptor results to upload dir:
[task 2019-10-30T15:01:11.243Z] 15:01:11     INFO - /Users/cltbld/tasks/task_1572447399/build/blobber_upload_dir/perfherder-data.json

Comment 6

[Florin Strugariu [:Bebe]]

:rwood maybe we can get someone to take a look over the browsertime error

Comment 7

[Andrew Creskey [:acreskey]]

Bebe, if it's helpful, it looks like raptor's self.gecko_profiler is null here.
You can verify what's happening in the initialization:
https://searchfox.org/mozilla-central/rev/3300072e993ae05d50d5c63d815260367eaf9179/testing/raptor/raptor/raptor.py#725-733

Comment 8

[Andrew Creskey [:acreskey]]

Maybe MOZ_UPLOAD_DIR not set?

Comment 9

[Florin Strugariu [:Bebe]]

I have fixed the python error.

The js issue is also "captured" in https://github.com/mozilla/browsertime/issues/42

Comment 10

[Robert Wood [:rwood]]

Hey :bebe what is the status of this (did you say there is still an error when running gecko profiling via raptor --browsertime)? Thanks!

Comment 11

[Florin Strugariu [:Bebe]]

:rwood see Comment 9
We are blocked on the Browsertime JS part

Comment 12

[Tarek Ziadé (:tarek)]

also, looks like the responsiveness feature is not recognized

[2019-12-05 10:06:56] DEBUG: [browsertime] Waiting after load event for 5000 ms.
[2019-12-05 10:07:01] INFO: [browsertime] Waiting for 30000 ms (post_startup_delay)
[2019-12-05 10:07:31] INFO: [browsertime] Cycle 0, waiting for 1000 ms
[2019-12-05 10:07:32] INFO: [browsertime] Cycle 0, starting the measure
[2019-12-05 10:07:32] INFO: [browsertime.command.measure] Testing url https://www.google.com/search?hl=en&q=barack+obama&cad=h iteration 1
[2019-12-05 10:07:32] VERBOSE: [browsertime] Executing privileged script Get StartProfiler.length
[2019-12-05 10:07:32] INFO: [browsertime.firefox] Start GeckoProfiler.
[2019-12-05 10:07:32] VERBOSE: [browsertime] Executing privileged script Start GeckoProfiler

Unrecognized feature "responsiveness".

Comment 13

[Tarek Ziadé (:tarek)]

I was able to make it work on warm load tests pending this patch: https://github.com/mozilla/browsertime/pull/50

Nick's issue on browsertime is a bit cryptic to me. But it looks like an improvement we can do later.

Comment 15

[Tarek Ziadé (:tarek)]

latest try run https://treeherder.mozilla.org/#/jobs?repo=try&tier=1%2C2%2C3&revision=f041bd65ffecca9122a26181d94233c3f6ada3f2

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/12c1e0fcd544
Add gecko profiling support to raptor-browsertime r=rwood,perftest-reviewers

Comment 17

[Dorel Luca [:dluca]]

https://hg.mozilla.org/mozilla-central/rev/12c1e0fcd544