Intermittent test_master_password.html | checking expected user to have been filled in - got , expected user1 (and more)

RESOLVED FIXED in Firefox 29

Status

()

RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: emorley, Assigned: MattN)

Tracking

({intermittent-failure})

Trunk
mozilla29
x86
Windows 7
intermittent-failure
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox27 disabled, firefox28 disabled, firefox29 fixed, firefox-esr24 unaffected, b2g-v1.2 disabled)

Details

Attachments

(1 attachment)

Windows 7 32-bit mozilla-central opt test mochitest-5 on 2013-09-18 04:30:46 PDT for push 0cbf1eec74ba

slave: t-w732-ix-063

https://tbpl.mozilla.org/php/getParsedLog.php?id=28031979&tree=Mozilla-Central

{
04:37:48     INFO -  122405 INFO TEST-PASS | /tests/toolkit/components/passwordmgr/test/test_master_password.html | Checking empty prompt
04:37:48     INFO -  122406 INFO TEST-PASS | /tests/toolkit/components/passwordmgr/test/test_master_password.html | handleDialog done
04:37:48     INFO -  122407 INFO TEST-PASS | /tests/toolkit/components/passwordmgr/test/test_master_password.html | checkTest3 starting
04:37:48     INFO -  122408 INFO TEST-PASS | /tests/toolkit/components/passwordmgr/test/test_master_password.html | handleDialog was invoked
04:37:48     INFO -  122409 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/components/passwordmgr/test/test_master_password.html | checking expected user to have been filled in - got , expected user1
04:37:48     INFO -  122410 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/components/passwordmgr/test/test_master_password.html | checking expected pass to have been filled in - got , expected pass1
04:37:48     INFO -  122411 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/components/passwordmgr/test/test_master_password.html | should be logged in
04:38:02     INFO -  122412 INFO TEST-PASS | /tests/toolkit/components/passwordmgr/test/test_master_password.html | should be logged out
04:38:02     INFO -  WARNING: pipe error: 109: file e:/builds/moz2_slave/m-cen-w32-00000000000000000000/build/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 312
04:38:02     INFO -  NPP_Destroy
04:38:02     INFO -  NPP_Destroy
04:38:02     INFO -  NPP_Destroy
04:38:02     INFO -  NPP_Destroy
04:38:02     INFO -  NPP_Destroy
04:43:14     INFO -  NPP_Destroy
04:43:14     INFO -  122413 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/components/passwordmgr/test/test_master_password.html | Test timed out.
}
(...and more)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
dolske, don't suppose you have any ideas what could have started this failing in the last ~3 days?
Flags: needinfo?(dolske)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Maybe bug 874502? That made window closing async, so maybe the prompt (window) isn't getting torn down synchronously any more, and thus maybe PSM's prompt call doesn't return until that event loop goes away? [I'm not exactly sure when those steps happen / how 874502 affects it, so that could all be wrong.]

The test polls (via a timer, see prompt_common.js) for the dialog to appear. Then it fills in the master password, calls dialog.acceptDialog(), and invokes via checkTest3() via executeSoon. Presumably the executeSoon is now, uhm, too soon. Perhaps DOMModalDialogClosed fires at the correct time, and we should listen for that instead of using executeSoon? [Could probably drop the polling and use DOMWillOpenModalDialog, but that seems to be working fine at the moment.]

This could also be manifesting in the other password manager prompt tests, which do very similar things (eg, for the HTTP auth prompt).
Flags: needinfo?(dolske) → needinfo?(bzbarsky)
Bobby?
Flags: needinfo?(bzbarsky) → needinfo?(bobbyholley+bmo)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(In reply to Justin Dolske [:Dolske] from comment #30)
> Maybe bug 874502? That made window closing async, so maybe the prompt
> (window) isn't getting torn down synchronously any more, and thus maybe
> PSM's prompt call doesn't return until that event loop goes away? [I'm not
> exactly sure when those steps happen / how 874502 affects it, so that could
> all be wrong.]
> 
> The test polls (via a timer, see prompt_common.js) for the dialog to appear.
> Then it fills in the master password, calls dialog.acceptDialog(), and
> invokes via checkTest3() via executeSoon. Presumably the executeSoon is now,
> uhm, too soon.

Does checkTest3 require that the window be closed in order for its state to be correct? If so, and depending on when the close sequence is initiated, that could explain it. The closing code does either 1 or 2 round-trips through the event loop depending on some mumbo-jumbo - so maybe when it's 2 we go oransge here?


> Perhaps DOMModalDialogClosed fires at the correct time, and
> we should listen for that instead of using executeSoon? [Could probably drop
> the polling and use DOMWillOpenModalDialog, but that seems to be working
> fine at the moment.]

I think we need to fix bug 917371.
Flags: needinfo?(bobbyholley+bmo)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Depends on: 917371
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Dolske, what needs to be done to prioritize bug 917371? This bug is quickly becoming a top orange on both trunk and aurora. I'm afraid we're going to be looking at disabling this test before too long.
Flags: needinfo?(dolske)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #90)
> Dolske, what needs to be done to prioritize bug 917371? This bug is quickly
> becoming a top orange on both trunk and aurora. I'm afraid we're going to be
> looking at disabling this test before too long.

I think that's a question for bholley, since his async window stuff regressed this. I'm happy to fix the test when we've got an event.
Flags: needinfo?(dolske) → needinfo?(bobbyholley+bmo)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
(In reply to Justin Dolske [:Dolske] from comment #113)
> (In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #90)
> > Dolske, what needs to be done to prioritize bug 917371? This bug is quickly
> > becoming a top orange on both trunk and aurora. I'm afraid we're going to be
> > looking at disabling this test before too long.
> 
> I think that's a question for bholley, since his async window stuff
> regressed this. I'm happy to fix the test when we've got an event.

This discussion should happen in bug 917371.
Flags: needinfo?(bobbyholley+bmo)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Test disabled for now for too many intermittent failures:
https://hg.mozilla.org/integration/mozilla-inbound/rev/c707564ee0df
Whiteboard: [test disabled][leave open]
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Note test disabling currently not having an effect due to bug 921987.
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
We now have an event. Returning NEEDINFO to dolske.
Flags: needinfo?(dolske)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
Comment hidden (Treeherder Robot)
I think previous comments explain a path for fixing this, but clearly I'm failing at getting around to it. Matt, can you take a crack at this? Would be good to restore our MP test coverage.
Flags: needinfo?(dolske) → needinfo?(MattN+bmo)
Created attachment 8368409 [details] [diff] [review]
v.1 Use outer-window-destroyed

Waits for outer-window-destroyed when necessary before running the next test.

I diffed the output before and after my patch to ensure that all the checks are all still running and in the same order.

Try push: https://tbpl.mozilla.org/?tree=Try&rev=0a48aed23ecf
Assignee: nobody → MattN+bmo
Status: NEW → ASSIGNED
Attachment #8368409 - Flags: review?(dolske)
Flags: needinfo?(MattN+bmo)
Attachment #8368409 - Flags: review?(dolske) → review+
https://hg.mozilla.org/mozilla-central/rev/ee7513d5f51f
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla29
status-b2g-v1.2: --- → disabled
status-firefox27: --- → disabled
status-firefox28: --- → disabled
status-firefox29: --- → fixed
status-firefox-esr24: --- → unaffected
You need to log in before you can comment on or make changes to this bug.