Closed Bug 1775847 Opened 2 years ago Closed 5 months ago

Intermittent browser/components/asrouter/tests/browser/browser_asrouter_cfr.js | single tracking bug

Categories

(Firefox :: Messaging System, defect, P1)

Product:
Firefox
Component:
Messaging System
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
127 Branch
Iteration:
127.1 - Apr 15 - Apr 26
Tracking Flags:
Tracking Status
firefox-esr115 --- wontfix
firefox125 --- wontfix
firefox126 --- fixed
firefox127 --- fixed

People

(Reporter: jmaher, Assigned: pdahiya)

References

Details

(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [stockwell unknown])

Attachments

(2 files, 1 obsolete file)

Bug 1775847 - Fix Glean timeout in browser_asrouter_cfr.js. r=#omc-reviewers
48 bytes, text/x-phabricator-request
Details | Review
Bug 1775847 - Fix intermittent milestone message and accessibility cfr test failure
48 bytes, text/x-phabricator-request
Details | Review
No description provided.

Additional information about this bug failures and frequency patterns can be found by running: ./mach test-info failure-report --bug 1775847

Component: New Tab Page → Messaging System
Severity: -- → S3
See Also: → 1880677
Assignee: nobody → shughes
Status: NEW → ASSIGNED
Summary: Intermittent browser/components/newtab/test/browser/browser_asrouter_cfr.js | single tracking bug → Intermittent browser/components/asrouter/tests/browser/browser_asrouter_cfr.js | single tracking bug
Duplicate of this bug: 1880677
Attachment #9382971 - Attachment is obsolete: true
Iteration: --- → 125.2 - Mar 4 - Mar 15
Priority: P3 → P1
Pushed by shughes@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/599787146257 Fix Glean timeout in browser_asrouter_cfr.js. r=omc-reviewers,pdahiya

https://hg.mozilla.org/mozilla-central/rev/599787146257

Status: ASSIGNED → RESOLVED
Closed: 7 months ago
status-firefox125: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 125 Branch

Hi, can you please take another look, we still have this on autoland: https://treeherder.mozilla.org/logviewer?job_id=450052478&repo=autoland

Flags: needinfo?(shughes)

(In reply to Cristian Tuns from comment #99)

Hi, can you please take another look, we still have this on autoland: https://treeherder.mozilla.org/logviewer?job_id=450052478&repo=autoland

Yes, thanks. That failure is also on our radar. I believe it's unrelated to the Glean hanging issue I fixed in the patch. It just happens to look the same as they're both timeouts, but the failure I fixed (the one from bug 1880677) was hanging on the Glean call at the end of the test, whereas this one is hanging on a button being focused. I'm not certain of the cause, but I have a couple ideas to test next week. We can keep this bug open or file a new one, whatever works best.

Flags: needinfo?(shughes)
Status: RESOLVED → REOPENED
status-firefox125: fixed → ---
Resolution: FIXED → ---
Target Milestone: 125 Branch → ---
Iteration: 125.2 - Mar 4 - Mar 15 → 126.1 - Mar 18 - Mar 29

Update

There have been 31 total failures within the last 7 days:

  • 14 failures on Linux 18.04 x64 WebRender opt/ debug
  • 11 failures on Linux 18.04 x64 WebRender Shippable opt
  • 3 failures on OS X 10.15 WebRender opt
  • 1 failure on Windows 11 x86 22H2 WebRender opt
  • 1 failure on Windows 11 x64 22H2 WebRender Shippable opt
  • 1 failure on Windows 11 x64 22H2 WebRender opt

Recent log: https://treeherder.mozilla.org/logviewer?job_id=452034961&repo=mozilla-central&lineNumber=5268

Whiteboard: [stockwell needswork:owner]
Iteration: 126.1 - Mar 18 - Mar 29 → 126.2 - Apr 1 - Apr 12

If someone else wants to take a crack at this one, please feel free.

Assignee: shughes → nobody
Iteration: 126.2 - Apr 1 - Apr 12 → 127.1 - Apr 15 - Apr 26

Update

There have been 34 failures within the last 7 days:

  • 10 failures on Linux 18.04 x64 WebRender opt
  • 13 failures on Linux 18.04 x64 WebRender Shippable opt
  • 1 failure on OS X 10.15 WebRender debug
  • 6 failures on OS X 10.15 WebRender Shippable opt
  • 3 failures on Windows 11 x64 22H2 WebRender opt
  • 1 failure on Windows 11 x64 22H2 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=455253491&repo=autoland&lineNumber=2284

[task 2024-04-20T07:39:16.391Z] 07:39:16     INFO - TEST-PASS | browser/components/asrouter/tests/browser/browser_asrouter_cfr.js | Should have removed the notification - 0 == 0 - 
[task 2024-04-20T07:39:16.391Z] 07:39:16     INFO - Leaving test bound test_cfr_addon_install
[task 2024-04-20T07:39:16.391Z] 07:39:16     INFO - Entering test bound test_cfr_tracking_protection_milestone_notification_remove
[task 2024-04-20T07:39:16.392Z] 07:39:16     INFO - Console message: 1713598756197	addons.xpi	WARN	Download of http://example.com/ failed: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIZipReader.open]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/addons/XPIInstall.sys.mjs :: XPIPackage :: line 311"  data: no] Stack trace: XPIPackage()@resource://gre/modules/addons/XPIInstall.sys.mjs:311
[task 2024-04-20T07:39:16.392Z] 07:39:16     INFO - get()@resource://gre/modules/addons/XPIInstall.sys.mjs:209
[task 2024-04-20T07:39:16.392Z] 07:39:16     INFO - loadManifest()@resource://gre/modules/addons/XPIInstall.sys.mjs:1574
[task 2024-04-20T07:39:16.392Z] 07:39:16     INFO - onStopRequest()@resource://gre/modules/addons/XPIInstall.sys.mjs:2651
[task 2024-04-20T07:39:16.393Z] 07:39:16     INFO - Buffered messages finished
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - TEST-UNEXPECTED-FAIL | browser/components/asrouter/tests/browser/browser_asrouter_cfr.js | Panel should be visible - false == true - {"filename":"chrome://mochitests/content/browser/browser/components/asrouter/tests/browser/browser_asrouter_cfr.js","name":"checkCFRTrackingProtectionMilestone","sourceId":640,"lineNumber":119,"columnNumber":10,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/browser/components/asrouter/tests/browser/browser_asrouter_cfr.js","name":"test_cfr_tracking_protection_milestone_notification_remove","sourceId":640,"lineNumber":538,"columnNumber":40,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"handleTask","sourceId":573,"lineNumber":1139,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"_runTaskBasedTest","sourceId":573,"lineNumber":1211,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"Tester_execTest","sourceId":573,"lineNumber":1353,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"nextTest/<","sourceId":573,"lineNumber":1128,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/tests/SimpleTest/SimpleTest.js","name":"SimpleTest.waitForFocus/<","sourceId":601,"lineNumber":1058,"columnNumber":13,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"nextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"async*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18\nasync*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"async*handleTask@chrome://mochikit/content/browser-test.js:1139:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18\nasync*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"test_cfr_tracking_protection_milestone_notification_remove@chrome://mochitests/content/browser/browser/components/asrouter/tests/browser/browser_asrouter_cfr.js:538:40\nasync*handleTask@chrome://mochikit/content/browser-test.js:1139:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18\nasync*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"checkCFRTrackingProtectionMilestone@chrome://mochitests/content/browser/browser/components/asrouter/tests/browser/browser_asrouter_cfr.js:119:10\ntest_cfr_tracking_protection_milestone_notification_remove@chrome://mochitests/content/browser/browser/components/asrouter/tests/browser/browser_asrouter_cfr.js:538:40\nasync*handleTask@chrome://mochikit/content/browser-test.js:1139:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18\nasync*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}}
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - Stack trace:
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - chrome://mochitests/content/browser/browser/components/asrouter/tests/browser/browser_asrouter_cfr.js:checkCFRTrackingProtectionMilestone:119
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - chrome://mochitests/content/browser/browser/components/asrouter/tests/browser/browser_asrouter_cfr.js:test_cfr_tracking_protection_milestone_notification_remove:538
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - chrome://mochikit/content/browser-test.js:handleTask:1139
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1211
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1353
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1128
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2024-04-20T07:39:16.397Z] 07:39:16     INFO - Not taking screenshot here: see the one that was previously logged

Hi Punam, do you have a few minutes to help us assign this to someone?
Thank you.

Flags: needinfo?(pdahiya)

Removing priority flag so that this gets re-triaged today. Thanks

Flags: needinfo?(pdahiya)
Priority: P1 → --
Assignee: nobody → pdahiya

NI Shane for updating bug with his findings of what could be causing this failure thanks

Flags: needinfo?(shughes)
Priority: -- → P1

I don't know what the problem is. I couldn't reproduce it on Windows.

Flags: needinfo?(shughes)

Shane. In Comment 100, you wrote:

I'm not certain of the cause, but I have a couple ideas to test next week.

If you happen to recall those ideas, they could be good places to start from...

Flags: needinfo?(shughes)

(In reply to Dan Mosedale (:dmosedale, :dmose) from comment #115)

Shane. In Comment 100, you wrote:

I'm not certain of the cause, but I have a couple ideas to test next week.

If you happen to recall those ideas, they could be good places to start from...

At the time I wrote that comment, there was a different prevailing failure. I added this comment in phabricator about it:

! In D202078#6995072, @aminomancer wrote:
This seems to be where it's timing out, since it never reaches the following assertion.
And the screenshot shows that the panel did open correctly (though its styling looks pretty messed up lol).
So it seems like there is an intermittent problem transferring focus to the panel.

The test doesn't wait for focus on the button before hitting spacebar. It just synchronously calls button.focus() and then waits for the panel to be focused.
But I don't think Element.focus() instantly focuses the element. So it may not even be focused before the test hits spacebar, yielding a race condition.
We could try waiting for focus before hitting spacebar. And maybe removing the tabindex attribute later.

  button.setAttribute("tabindex", "-1");
  let buttonFocused = BrowserTestUtils.waitForEvent(button, "focus");
  button.focus();
  await buttonFocused;
  let panelFocused = BrowserTestUtils.waitForEvent(
    PopupNotifications.panel,
    "focus",
    true
  );
  EventUtils.synthesizeKey(" ");
  await panelFocused;
  Assert.ok(true, "Focus inside panel after button pressed");
  button.removeAttribute("tabindex");

If you want, I can add those changes to this patch. Otherwise I'll attempt the fix after this lands.

But as for the current "Panel should be visible" failure, I don't have any ideas about the cause (seems like it could be a lot of things).

Flags: needinfo?(shughes)

My findings so far, browser_asrouter_cfr.js is failing intermittently at two places a) keyboard cfr test here for mochitest-browser-chrome-swr-a11y-checks-5 test suite on linux b) Tracking protection milestone message mochitest on macosx and windows.

Both these tests exists for a while. Last patch that touched CFR which is in close vicinity of when tests started failing though unclear what triggers intermittent race conditions.

Try run with failing tests:
https://treeherder.mozilla.org/jobs?repo=try&revision=491adaeee10ea656e0c9d4590e7dfe3fbf619af0

Try run with patch isolating above two failing tests in their own files:
https://treeherder.mozilla.org/jobs?repo=try&revision=eed1091e337e45b3a6fc64ee20f8b001725d3214

So far isolating the tests seems to help fix both intermittent failures

Attached patch isolates failing tests in their own respective test files and added extra awaits for focused event recommended in #comment 116 that seems to be helping with race conditions.

Filed follow ups Bug 1893675 and Bug 1893671 , noticed while debugging that could have led to increases in frequency of failures seen in browser_asrouter_cfr tests and should help maintain these tests better

See Also: → 1893675, 1893671
Pushed by pdahiya@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/8d9444646b63 Fix intermittent milestone message and accessibility cfr test failure r=omc-reviewers,negin

https://hg.mozilla.org/mozilla-central/rev/8d9444646b63

Status: REOPENED → RESOLVED
Closed: 7 months ago → 5 months ago
status-firefox127: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 127 Branch
No longer depends on: 1714317, 1768496, 1768966, 1770305, 1771773, 1772596
See Also: 1880677 →

The patch landed in nightly and beta is affected.
:pdahiya, is this bug important enough to require an uplift?

  • If yes, please nominate the patch for beta approval.
  • If no, please set status-firefox126 to wontfix.

For more information, please visit BugBot documentation.

Flags: needinfo?(pdahiya)

This is a test-only change and does not need a formal uplift request.
We can take it in an push later.

Flags: needinfo?(pdahiya)
Duplicate of this bug: 1895135
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: