1605940 - Perma beta browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | Test timed out - when Gecko 73 merges to Beta on 2020-01-06

Status: VERIFIED FIXED

(Firefox :: Address Bar, defect)

Description

[Stefan Hindli [:stefan_hindli]]

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=282599613&repo=try&lineNumber=3602

task 2019-12-25T14:19:51.993Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | extra[selIndex] must match in event urlbar#engagement#click. - "0" matches "0" -
[task 2019-12-25T14:19:51.993Z] 14:19:51 INFO - Running test at index 17
[task 2019-12-25T14:19:51.993Z] 14:19:51 INFO - Open the panel with dropmarker, type something, Enter.
[task 2019-12-25T14:19:51.993Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | parent must be in snapshot. Has [parent]. - true == true -
[task 2019-12-25T14:19:51.994Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | After filtering we must have the expected number of events. - 1 == 1 -
[task 2019-12-25T14:19:51.996Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | category in event urlbar#engagement#enter must match. - "urlbar" matches "urlbar" -
[task 2019-12-25T14:19:51.996Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | method in event urlbar#engagement#enter must match. - "engagement" matches "engagement" -
[task 2019-12-25T14:19:51.996Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | object in event urlbar#engagement#enter must match. - "enter" matches "enter" -
[task 2019-12-25T14:19:51.996Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | value in event urlbar#engagement#enter must match. - "topsites" matches "topsites" -
[task 2019-12-25T14:19:51.997Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | Actual event urlbar#engagement#enter expected to have extra. - true == true -
[task 2019-12-25T14:19:51.997Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | Expected key elapsed must be in actual extra. Actual keys: [elapsed,numChars,selIndex,selType]. - true == true -
[task 2019-12-25T14:19:51.997Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | extra[elapsed] must match in event urlbar#engagement#enter. - "242" matches "val => parseInt(val) > 0" -
[task 2019-12-25T14:19:51.999Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | Expected key numChars must be in actual extra. Actual keys: [elapsed,numChars,selIndex,selType]. - true == true -
[task 2019-12-25T14:19:51.999Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | extra[numChars] must match in event urlbar#engagement#enter. - "1" matches "1" -
[task 2019-12-25T14:19:51.999Z] 14:19:51 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | Expected key selType must be in actual extra. Actual keys: [elapsed,numChars,selIndex,selType]. - true == true -
[task 2019-12-25T14:19:52.000Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | extra[selType] must match in event urlbar#engagement#enter. - "search" matches "search" -
[task 2019-12-25T14:19:52.002Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | Expected key selIndex must be in actual extra. Actual keys: [elapsed,numChars,selIndex,selType]. - true == true -
[task 2019-12-25T14:19:52.002Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | extra[selIndex] must match in event urlbar#engagement#enter. - "0" matches "0" -
[task 2019-12-25T14:19:52.003Z] 14:19:52 INFO - Running test at index 18
[task 2019-12-25T14:19:52.003Z] 14:19:52 INFO - With pageproxystate=valid, open the panel with openViewOnFocus, select with DOWN, Enter.
[task 2019-12-25T14:19:52.003Z] 14:19:52 INFO - Buffered messages logged at 14:19:14
[task 2019-12-25T14:19:52.005Z] 14:19:52 INFO - Console message: [JavaScript Error: "getScreenshot(http://example.org/) failed: TypeError: NetworkError when attempting to fetch resource." {file: "resource://activity-stream/lib/Screenshots.jsm" line: 59}]
[task 2019-12-25T14:19:52.005Z] 14:19:52 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:59:10
[task 2019-12-25T14:19:52.005Z] 14:19:52 INFO -
[task 2019-12-25T14:19:52.006Z] 14:19:52 INFO - Buffered messages finished
[task 2019-12-25T14:19:52.006Z] 14:19:52 INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | Test timed out -
[task 2019-12-25T14:19:52.006Z] 14:19:52 INFO - GECKO(2047) | MEMORY STAT | vsize 7790MB | residentFast 470MB | heapAllocated 155MB
[task 2019-12-25T14:19:52.006Z] 14:19:52 INFO - TEST-OK | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | took 45099ms
[task 2019-12-25T14:19:52.009Z] 14:19:52 INFO - checking window state
[task 2019-12-25T14:19:52.009Z] 14:19:52 INFO - TEST-START | browser/components/urlbar/tests/browser/browser_urlbar_locationchange_urlbar_edit_dos.js
[task 2019-12-25T14:19:52.357Z] 14:19:52 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-12-25T14:19:52.357Z] 14:19:52 INFO - Buffered messages logged at 14:19:51
[task 2019-12-25T14:19:52.357Z] 14:19:52 INFO - Entering test bound
[task 2019-12-25T14:19:52.358Z] 14:19:52 INFO - Buffered messages logged at 14:19:52
[task 2019-12-25T14:19:52.358Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_locationchange_urlbar_edit_dos.js | URL bar value should match after sending a key -
[task 2019-12-25T14:19:52.358Z] 14:19:52 INFO - Buffered messages finished
[task 2019-12-25T14:19:52.358Z] 14:19:52 INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js | Uncaught exception received from previously timed out test - at chrome://mochitests/content/browser/browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js:501 - ReferenceError: UrlbarTestUtils is not defined
[task 2019-12-25T14:19:52.358Z] 14:19:52 INFO - Stack trace:
[task 2019-12-25T14:19:52.358Z] 14:19:52 INFO - tests<@chrome://mochitests/content/browser/browser/components/urlbar/tests/browser/browser_urlbar_event_telemetry.js:501:5
[task 2019-12-25T14:19:52.539Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_locationchange_urlbar_edit_dos.js | Should only get a same document location change -
[task 2019-12-25T14:19:52.539Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_locationchange_urlbar_edit_dos.js | URL bar should not have been changed by location changes. -
[task 2019-12-25T14:19:52.543Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_locationchange_urlbar_edit_dos.js | URL bar value should match after sending a key -
[task 2019-12-25T14:19:52.689Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_locationchange_urlbar_edit_dos.js | Should only get a same document location change -
[task 2019-12-25T14:19:52.689Z] 14:19:52 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_urlbar_locationchange_urlbar_edit_dos.js | URL bar should not have been changed by location changes. -
[task 2019-12-25T14:19:52.693Z] 14:19:52 INFO - Leaving test bound
[task 2019-12-25T14:19:52.740Z] 14:19:52 INFO - GECKO(2047) | MEMORY STAT | vsize 7783MB | residentFast 470MB | heapAllocated 157MB
[task 2019-12-25T14:19:52.742Z] 14:19:52 INFO - TEST-OK | browser/components/urlbar/tests/browser/browser_urlbar_locationchange_urlbar_edit_dos.js | took 791ms
[task 2019-12-25T14:19:52.748Z] 14:19:52 INFO - checking window state
[task 2019-12-25T14:19:52.762Z] 14:19:52 INFO - TEST-START | browser/components/urlbar/tests/browser/browser_urlbar_remoteness_switch.js
[task 2019-12-25T14:19:53.412Z] 14:19:53 INFO - GECKO(2047) | MEMORY STAT | vsize 7788MB | residentFast 471MB | heapAllocated 165MB

Comment 1

[Stefan Hindli [:stefan_hindli]]

[Tracking Requested - why for this release]:

Comment 2

[Cosmin Sabou [:CosminS]]

Central as beta-simulation: https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=11f75cc87882200a3e5d6159f83608b33760137b&searchStr=browser%2Cchrome&selectedJob=282591238

Looks to be from Bug 1604932 https://hg.mozilla.org/mozilla-central/rev/f6a7e3d2a75386db5685db7779abe90dd932905e
Harry, please take a look over this. Thank you.

Comment 3

[Intermittent Failures Robot]

31 failures in 95 pushes (0.326 failures/push) were associated with this bug yesterday.

Repository breakdown:

• try: 31

Platform breakdown:

• linux64: 4
• macosx1014-64-devedition: 2
• windows7-32: 2
• windows10-64: 4
• windows10-64-qr: 2
• linux64-devedition: 2
• linux64-shippable: 2
• macosx1014-64-shippable: 2
• windows7-32-devedition: 2
• windows10-64-devedition: 2
• windows7-32-shippable: 2
• windows10-64-shippable-qr: 2
• windows10-64-shippable: 2
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1605940&startday=2019-12-25&endday=2019-12-25&tree=all

Comment 4

[Intermittent Failures Robot]

31 failures in 1365 pushes (0.023 failures/push) were associated with this bug in the last 7 days.

This is the #26 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• try: 31

Platform breakdown:

• linux64: 4
• macosx1014-64-devedition: 2
• windows7-32: 2
• windows10-64: 4
• windows10-64-qr: 2
• linux64-devedition: 2
• linux64-shippable: 2
• macosx1014-64-shippable: 2
• windows7-32-devedition: 2
• windows10-64-devedition: 2
• windows7-32-shippable: 2
• windows10-64-shippable-qr: 2
• windows10-64-shippable: 2
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1605940&startday=2019-12-23&endday=2019-12-29&tree=all

Comment 5

[Harry Twyford]

I expect this is fixed by bug 1605888.

Comment 6

[Cosmin Sabou [:CosminS]]

Harry, this is still showing up even after bug 1605888 is fixed: https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=75154cf5ede0bc8e86fbead9dc251e6b95646b64&searchStr=browser%2Cchrome&selectedJob=283123779

Comment 7

[Harry Twyford]

Attachment: Bug 1605940 - Explicitly enable the openViewOnFocus pref so browser_urlbar_event_telemetry works in Beta. r?mikedeboer

Comment 8

[Alexandru Michis [:malexandru]]

Harry,
Importing your patch causes Bug 1606814 to appear, can you please take a look?

Comment 10

[Harry Twyford]

Alexandru, are you referring to the Phabricator patch posted in this thread? Like you applied the patch from Phabricator and that's what's causing this new failure? Or just the patch from Bug 1604932?

Comment 11

[Alexandru Michis [:malexandru]]

Sorry,
I meant the patch from comment 7 (https://phabricator.services.mozilla.com/D58524).

Comment 12

[Harry Twyford]

Thanks. I've updated the patch. Could it please be run again on the next beta-simulation?

Comment 13

[Alexandru Michis [:malexandru]]

Thank you, we'll add it in tomorrow's beta simulation.

Comment 14

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

The patch works according to this central-as-beta simulation: https://treeherder.mozilla.org/#/jobs?repo=try&revision=2deee041a8d7dd4fabc2095c0c87b5fd49174e83

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/55875e2e7f4a
Explicitly enable the openViewOnFocus pref so browser_urlbar_event_telemetry works in Beta. r=mikedeboer

Comment 16

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/releases/mozilla-beta/rev/91609377ed79

Comment 17

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/55875e2e7f4a

Comment 18

[Andreea Pavel [:apavel]]

Verified fixed in the latest beta sim: https://treeherder.mozilla.org/#/jobs?repo=try&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=828df1c4377b2a99d7c256c9b33ce02f67f6c5cb

Comment 19

[Intermittent Failures Robot]

8 failures in 4472 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 8

Platform breakdown:

• linux64: 1
• windows7-32-devedition: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1605940&startday=2020-01-06&endday=2020-01-12&tree=all

Comment 20

[Alexandru Ionescu (needinfo me) [:alexandrui]]

Harry, makes sense that this patch caused this dual modality?

Comment 21

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

The change only modifies two browser-chrome test files, performance tests must be unaffected (binary and performance test framework unchanged). The dual modality disappeared later. If it affects more tests, you can ask :dhouse if there was work ongoing on the macOS machines.