Closed Bug 1581889 Opened 6 years ago Closed 3 years ago

Intermittent browser/components/aboutlogins/tests/browser/browser_openSite.js | Test timed out -

Categories

(Firefox :: about:logins, defect, P3)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1775756
Tracking Status
firefox-esr78 --- unaffected
firefox-esr91 --- disabled
firefox91 --- wontfix
firefox92 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disabled])

Attachments

(2 files)

Filed by: rgurzau [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=267055268&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/Ozq8VBY8RWmqJ2UUD7n2cA/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/Ozq8VBY8RWmqJ2UUD7n2cA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2019-09-17T14:39:14.310Z] 14:39:14 INFO - TEST-INFO | started process screentopng
[task 2019-09-17T14:39:14.692Z] 14:39:14 INFO - TEST-INFO | screentopng: exit 0
[task 2019-09-17T14:39:14.692Z] 14:39:14 INFO - Buffered messages logged at 14:37:44
[task 2019-09-17T14:39:14.692Z] 14:39:14 INFO - Entering test bound setup
[task 2019-09-17T14:39:14.692Z] 14:39:14 INFO - Buffered messages logged at 14:37:45
[task 2019-09-17T14:39:14.692Z] 14:39:14 INFO - Leaving test bound setup
[task 2019-09-17T14:39:14.692Z] 14:39:14 INFO - Entering test bound test_launch_login_item
[task 2019-09-17T14:39:14.693Z] 14:39:14 INFO - TEST-PASS | browser/components/aboutlogins/tests/browser/browser_openSite.js | discard-changes confirmation-dialog should be hidden before opening the site - true == true -
[task 2019-09-17T14:39:14.693Z] 14:39:14 INFO - waiting for new tab to get opened
[task 2019-09-17T14:39:14.696Z] 14:39:14 INFO - Console message: [JavaScript Error: "Unknown Collection "main/fxmonitor-breaches"" {file: "resource://services-settings/RemoteSettingsClient.jsm" line: 172}]
[task 2019-09-17T14:39:14.696Z] 14:39:14 INFO - UnknownCollectionError@resource://services-settings/RemoteSettingsClient.jsm:172:5
[task 2019-09-17T14:39:14.697Z] 14:39:14 INFO - sync@resource://services-settings/RemoteSettingsClient.jsm:379:13
[task 2019-09-17T14:39:14.697Z] 14:39:14 INFO - asyncget@resource://services-settings/RemoteSettingsClient.jsm:325:22
[task 2019-09-17T14:39:14.698Z] 14:39:14 INFO - async
getPotentialBreachesByLoginGUID@resource:///modules/LoginBreaches.jsm:59:74
[task 2019-09-17T14:39:14.698Z] 14:39:14 INFO - receiveMessage@resource:///modules/AboutLoginsParent.jsm:418:61
[task 2019-09-17T14:39:14.699Z] 14:39:14 INFO - asyncreceiveMessage@resource:///modules/BrowserGlue.jsm:670:30
[task 2019-09-17T14:39:14.699Z] 14:39:14 INFO - MessageListener.receiveMessage
init@resource:///modules/BrowserGlue.jsm:685:19
[task 2019-09-17T14:39:14.701Z] 14:39:14 INFO - BG__beforeUIStartup@resource:///modules/BrowserGlue.jsm:1207:15
[task 2019-09-17T14:39:14.701Z] 14:39:14 INFO - BG_observe@resource:///modules/BrowserGlue.jsm:857:14
[task 2019-09-17T14:39:14.701Z] 14:39:14 INFO -
[task 2019-09-17T14:39:14.701Z] 14:39:14 INFO - Buffered messages finished
[task 2019-09-17T14:39:14.702Z] 14:39:14 INFO - TEST-UNEXPECTED-FAIL | browser/components/aboutlogins/tests/browser/browser_openSite.js | Test timed out -
[task 2019-09-17T14:39:14.702Z] 14:39:14 INFO - GECKO(3055) | [Child 3215, Main Thread] WARNING: '!mEditableNode', file /builds/worker/workspace/build/src/dom/events/IMEContentObserver.cpp, line 298
[task 2019-09-17T14:39:14.703Z] 14:39:14 INFO - GECKO(3055) | MEMORY STAT | vsize 2972MB | residentFast 320MB | heapAllocated 82MB
[task 2019-09-17T14:39:14.703Z] 14:39:14 INFO - TEST-OK | browser/components/aboutlogins/tests/browser/browser_openSite.js | took 90197ms
[task 2019-09-17T14:39:14.703Z] 14:39:14 INFO - GECKO(3055) | ++DOCSHELL 0x7f3b780ba800 == 1 [pid = 3244] [id = {0b3320dc-93cd-4df5-9572-f4eb9121358e}]
[task 2019-09-17T14:39:14.706Z] 14:39:14 INFO - GECKO(3055) | ++DOMWINDOW == 1 (0x7f3b785f2100) [pid = 3244] [serial = 9] [outer = (nil)]
[task 2019-09-17T14:39:14.706Z] 14:39:14 INFO - GECKO(3055) | ++DOMWINDOW == 2 (0x7f3b7817b000) [pid = 3244] [serial = 10] [outer = 0x7f3b785f2100]
[task 2019-09-17T14:39:14.707Z] 14:39:14 INFO - checking window state

Component: Password Manager → about:logins
Product: Toolkit → Firefox
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

On a try push for a stack that should not really affect this code at all, I got a Pernosco trace for this time out.

We reproduced the failure

TEST-UNEXPECTED-FAIL | browser/components/aboutlogins/tests/browser/browser_openSite.js | Test timed out - 

that may correspond to your recent failed test-linux1804-64/debug-mochitest-browser-chrome-fis-e10s-8 test job at https://treeherder.mozilla.org/#/jobs?repo=try&revision=0aea6aeeca0b4cbefad938cc2ff8517235abe728.

Go to https://pernos.co/debug/U88TNd14AgK_WOzR3RPB0A/index.html to debug it!
You can view the test harness output at https://s3.us-east-2.amazonaws.com/pernosco-logs/reproducer-mozilla-mozilla/Q_oxwYzLRwiJvS4sHTTwTA/DNgeYrjkRzCoattvR_Z34w-0954d2e0.log.gz

Maybe this will help someone investigate tihs?

There have been 43 total failures in the last 7 days (recent failure log).
Affected platforms are:

  • linux1804-64-asan-qr
  • linux1804-64-qr debug
  • linux1804-64-tsan-qr

Sam, could you please take a look?

Flags: needinfo?(sfoster)
Whiteboard: [stockwell needswork:owner]

There have been 48 total failures in the last 7 days, recent failure log.
Affected platforms are:

  • linux1804-64-asan-qr
  • linux1804-64-qr
[task 2021-08-13T23:34:03.036Z] 23:34:03     INFO - TEST-START | browser/components/aboutlogins/tests/browser/browser_openSite.js
[task 2021-08-13T23:35:33.049Z] 23:35:33     INFO - TEST-INFO | started process screentopng
[task 2021-08-13T23:35:33.644Z] 23:35:33     INFO - TEST-INFO | screentopng: exit 0
[task 2021-08-13T23:35:33.645Z] 23:35:33     INFO - Buffered messages logged at 23:34:03
[task 2021-08-13T23:35:33.646Z] 23:35:33     INFO - Entering test bound setup_head
[task 2021-08-13T23:35:33.646Z] 23:35:33     INFO - Leaving test bound setup_head
[task 2021-08-13T23:35:33.647Z] 23:35:33     INFO - Entering test bound setup
[task 2021-08-13T23:35:33.648Z] 23:35:33     INFO - Leaving test bound setup
[task 2021-08-13T23:35:33.649Z] 23:35:33     INFO - Entering test bound test_launch_login_item
[task 2021-08-13T23:35:33.649Z] 23:35:33     INFO - waiting for new tab to get opened
[task 2021-08-13T23:35:33.650Z] 23:35:33     INFO - Buffered messages finished
[task 2021-08-13T23:35:33.651Z] 23:35:33     INFO - TEST-UNEXPECTED-FAIL | browser/components/aboutlogins/tests/browser/browser_openSite.js | Test timed out - 
[task 2021-08-13T23:35:33.651Z] 23:35:33     INFO - Console message: SENTINEL
[task 2021-08-13T23:35:33.652Z] 23:35:33     INFO - GECKO(1561) | console.warn: LoginHelper(Content): "Couldn't parse origin for" "" ({})
[task 2021-08-13T23:35:33.653Z] 23:35:33     INFO - GECKO(1561) | MEMORY STAT | vsize 20975542MB | residentFast 1224MB
[task 2021-08-13T23:35:33.654Z] 23:35:33     INFO - TEST-OK | browser/components/aboutlogins/tests/browser/browser_openSite.js | took 90195ms
[task 2021-08-13T23:35:33.654Z] 23:35:33     INFO - checking window state
Severity: normal → --
Priority: P5 → --

Forwarding to :tgiles

Flags: needinfo?(sfoster) → needinfo?(tgiles)

Trying to reproduce on my linux 18.04 box. Listing out the steps to see what will and won't work:

  • Running the test by itself, mach test browser/components/aboutlogins/test/browser/browser_openSite.js --headless --enable-webrender --verify doesn't seem to reproduce.
  • Running the test by itself in headless and verify mode doesn't seem to reproduce when building Firefox with --enable-webrender=true.
  • Running the test by itself with MOZ_CHAOSMODE enabled (export MOZ_CHAOSMODE="0xfb") does not reproduce
  • Running the test by itself with MOZ_CHAOSMODE enabled with --run-until-failure does not reproduce.
  • Running the test by itself with MOZ_CHAOSMODE enabled with --run-until-failure in regular (non-headless) mode does not reproduce.
  • Running the test by itself in verify mode (which enables MOZ_CHAOSMODE) in regular (non-headless) mode does not reproduce.

I'm guessing the intermittent is something to due with the test before in because of the difficulty in reproducing (that or I haven't enable webrender correctly)...but according to our dev platform google group, it appears webrender should be enabled by default (which I'm guessing means I don't need to manually pass the webrender flag)

  • Running the browser chrome suite for aboutlogins (mach test browser/components/aboutlogins/test/browser --headless --enable-webrender) does not reproduce.
  • Running the browser chrome suite for aboutlogins with verify enabled does not reproduce
    • This ended up failing on browser_openImportCSV.js surprisingly
  • Running the browser chrome suite with MOZ_CHAOSMODE enabled does not reproduce.

I'm not going to clear the NI, but I've been unsuccessful in reproducing the failure condition locally so far. I guess I'll give it some time and see if the oranges spike up again and try again/ask :dimi for some assistance.

There have been 51 failures in the last 7 days.
Affected platforms:
-linux1804-64-asan-qr opt
-linux1804-64-qr debug
-linux1804-64-tsan-qr opt

Recent failure log

Assignee: nobody → tgiles
Flags: needinfo?(tgiles)

I was able to reproduce with some extra logging on Try. The extra logging tends to use "openSite:" as a prefix so that it's a bit easier to parse logs. Here's that Try run for reference. It looks like the test times out waiting for a new tab to be launched. I'm not quite sure why we would timeout waiting for a new tab to be launched. Maybe there's some timing issue with synthesizing the mouse at the center of the content... but we do successfully synthesize the event according to my logs.

Whiteboard: [stockwell disable-recommended] → [stockwell disabled][stockwell needswork:owner]
Keywords: leave-open
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/60697a776b8a disable browser_openSite.js on linux64 for frequent failures r=intermittent-reviewers,jmaher DONTBUILD

Backed out for causing failures on browser_removeAllDialog.js

[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - TEST-PASS | browser/components/aboutlogins/tests/browser/browser_removeAllDialog.js | Remove all button contents should match l10n-id attribute set on outer element - "about-logins-confirm-remove-all-dialog-confirm-button-label" == "about-logins-confirm-remove-all-dialog-confirm-button-label" - 
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - Buffered messages finished
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - TEST-UNEXPECTED-FAIL | browser/components/aboutlogins/tests/browser/browser_removeAllDialog.js | Title contents should match l10n-args attribute set on element - 6 == 1 - got 6, expected 1 (operator ==)
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - Stack trace:
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - is@resource://specialpowers/SpecialPowersSandbox.jsm:90:21
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - @chrome://mochitests/content/browser/browser/components/aboutlogins/tests/browser/browser_removeAllDialog.js:143:7
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - TEST-UNEXPECTED-FAIL | browser/components/aboutlogins/tests/browser/browser_removeAllDialog.js | Message contents should match l10n-args attribute set on element - 6 == 1 - got 6, expected 1 (operator ==)
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - Stack trace:
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - is@resource://specialpowers/SpecialPowersSandbox.jsm:90:21
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - @chrome://mochitests/content/browser/browser/components/aboutlogins/tests/browser/browser_removeAllDialog.js:148:7
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - TEST-UNEXPECTED-FAIL | browser/components/aboutlogins/tests/browser/browser_removeAllDialog.js | Label contents should match l10n-id attribute set on outer element - 6 == 1 - got 6, expected 1 (operator ==)
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - Stack trace:
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - is@resource://specialpowers/SpecialPowersSandbox.jsm:90:21
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - @chrome://mochitests/content/browser/browser/components/aboutlogins/tests/browser/browser_removeAllDialog.js:153:7
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - Leaving test bound test_remove_all_dialog_l10n
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - Entering test bound test_remove_all_dialog_keyboard_navigation
[task 2021-08-28T18:01:17.940Z] 18:01:17     INFO - GECKO(2045) | must wait for focus in content
[task 2021-08-28T18:01:17.964Z] 18:01:17     INFO - remove all dialog should be opened
[task 2021-08-28T18:01:17.977Z] 18:01:17     INFO - TEST-PASS | browser/components/aboutlogins/tests/browser/browser_removeAllDialog.js | Remove all should be disabled on dialog open - true == true -
Flags: needinfo?(tgiles)

Disabling browser_openSite.js has uncovered the permafailures mentioned above.

Tim, are there any updates on this?
Thank you.

Keywords: leave-open
Whiteboard: [stockwell disabled][stockwell needswork:owner] → [stockwell needswork:owner]

I haven't been able to pin down the issue yet. It looks like we have some dependencies in our testing order, if disabling the openSite test is now causing permafailures elsewhere.

I'll investigate and see if I can get something figured out. Keeping NI open as a reminder.

Alright I have a patch that I'll submit soon that will allow us to disable the browser_openSite test without creating permafailure elsewhere. I'll attach it as a parent of the current patch that disables the test, should make things easier to land and all that.

Flags: needinfo?(tgiles)
Pushed by tgiles@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/c34405e50fba Fix browser_openImportCSV.js not cleaning up logins after the test runs. r=dimi
Status: REOPENED → RESOLVED
Closed: 5 years ago4 years ago
Resolution: --- → FIXED
Target Milestone: --- → 93 Branch
Pushed by tgiles@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/1972acfd80ea disable browser_openSite.js on linux64 for frequent failures r=intermittent-reviewers,jmaher
Status: RESOLVED → REOPENED
Keywords: leave-open
Resolution: FIXED → ---
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Target Milestone: 93 Branch → ---
Assignee: tgiles → nobody

Setting to P3 as failure rate is very low

Severity: -- → S4
Priority: -- → P3
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: