Closed Bug 608206 Opened 9 years ago Closed 9 years ago

Intermittent timeout in test_prompt.html | Test timed out.

Categories

(Toolkit :: Password Manager, defect)

x86
Linux
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla7

People

(Reporter: jdm, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [disabled on linux])

Attachments

(1 file)

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1288335632.1288336184.4389.gz
Rev3 Fedora 12 mozilla-central opt test mochitests-5/5 on 2010/10/29 00:00:32

s: talos-r3-fed-049
6288 ERROR TEST-UNEXPECTED-FAIL | /tests/toolkit/components/passwordmgr/test/test_prompt.html | Test timed out.
Depends on: 482175
Comment on attachment 487334 [details] [diff] [review]
Specify specific actions to observe for password manager tests.

There are two main changes here:
* we now ensure that callbacks are only executed after specific storage events occur
* we eliminate a source of timeouts where we reset the iframe src and expect the prompt to appear. If the last login hasn't been removed yet, it'll never appear.
Attachment #487334 - Flags: review?(dolske)
Comment on attachment 487334 [details] [diff] [review]
Specify specific actions to observe for password manager tests.

I don't understand how this would fix the observed failures.

The last few logs end with:

5009 INFO TEST-PASS | test_prompt.html | finishTest removing testing logins...
5010 INFO TEST-PASS | test_prompt.html | currently have 10 logins.
5011 INFO TEST-PASS | test_prompt.html | removing login 2A...
5012 INFO TEST-PASS | test_prompt.html | removing login 2B...
5013 ERROR TEST-UNEXPECTED-FAIL | test_prompt.html | Test timed out.

So, it's (presumably?) throwing when trying to remove login 2B. But that login is last touched in test #507 (which was successful, as were all the other tests in the run), and the changes here only seem to deal with code well after that's done.
bug 612277 has been filed for the failure caused by the debug spew, if you eventually want to merge it here, or whatever.
So, looks like this is caused by observer notifications coming in unexpected order...

5113 INFO TEST-PASS | handleLoad running for test 1004
...
5123 INFO TEST-PASS | Triggering main action
5124 INFO TEST-PASS | observer for passwordmgr-storage-changed / modifyLogin
5125 INFO TEST-PASS | subject QI
5126 INFO TEST-PASS | should be 2 items - 2 should equal 2
5127 INFO TEST-PASS | oldLogin: host: http://mochi.test:8888 / formURL: null / realm: mochitest / user: mochiuser1 / pass: mochipass1 / ufield:  / pfield:
5128 INFO TEST-PASS | newLogin: host: http://mochi.test:8888 / formURL: null / realm: mochitest / user: mochiuser1 / pass: mochipass1-new / ufield:  / pfield:
5129 INFO TEST-PASS | 1004's clearIt() called.
5130 ERROR TEST-UNEXPECTED-FAIL | clearIt GOT EXCEPTION: No matching logins

Test 1004 is testing changing a password for "mochiuser3" from "mochipass3-old" to "mochipass3-new", that's the login/notification that clearIt() is expecting. Instead it's getting the notification from back in test 1002.

The really bizarre thing is that the log shows test that the same notification was received back in test 1003 where it was expected. O_o

So either we're somehow getting duplicated/buggy notifications, or something is triggering the test 1002 code again.
Blocks: 612683
The timeouts occurring in this bug show that even though we get an "password-save" prompt for 1005 and trigger the action, we apparently don't get a corresponding observer notification so we never run the finishIt callback and finish the test.