Closed Bug 917797 Opened 11 years ago Closed 10 years ago

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

Categories

(Toolkit :: Password Manager, defect)

x86
Windows 7
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla29
Tracking Status
firefox27 --- disabled
firefox28 --- disabled
firefox29 --- fixed
firefox-esr24 --- unaffected
b2g-v1.2 --- disabled

People

(Reporter: emorley, Assigned: MattN)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

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)
dolske, don't suppose you have any ideas what could have started this failing in the last ~3 days?
Flags: needinfo?(dolske)
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)
(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)
Depends on: 917371
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)
(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)
(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)
Test disabled for now for too many intermittent failures:
https://hg.mozilla.org/integration/mozilla-inbound/rev/c707564ee0df
Whiteboard: [test disabled][leave open]
Note test disabling currently not having an effect due to bug 921987.
We now have an event. Returning NEEDINFO to dolske.
Flags: needinfo?(dolske)
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)
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/integration/fx-team/rev/ee7513d5f51f
Whiteboard: [test disabled][leave open]
https://hg.mozilla.org/mozilla-central/rev/ee7513d5f51f
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla29
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: