Closed Bug 1325778 Opened 7 years ago Closed 5 years ago

Intermittent toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Test timed out.

Categories

(Toolkit :: Password Manager, defect, P2)

defect

Tracking

()

RESOLVED FIXED
Tracking Status
firefox52 --- disabled
firefox-esr52 --- disabled
firefox53 --- disabled
firefox54 --- disabled

People

(Reporter: intermittent-bug-filer, Assigned: jaws)

Details

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

Attachments

(4 files, 1 obsolete file)

[task 2017-01-19T07:47:04.915849Z] 07:47:04     INFO - SpawnTask.js | Leaving test test_form11_recipes
[task 2017-01-19T07:47:04.917268Z] 07:47:04     INFO - SpawnTask.js | Entering test test_form12_formless
[task 2017-01-19T07:47:04.918742Z] 07:47:04     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 username is:  
[task 2017-01-19T07:47:04.920294Z] 07:47:04     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 password is:  
[task 2017-01-19T07:47:04.921972Z] 07:47:04     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 username is:  
[task 2017-01-19T07:47:04.923498Z] 07:47:04     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 password is:  
[task 2017-01-19T07:47:04.924791Z] 07:47:04     INFO - Buffered messages finished
[task 2017-01-19T07:47:04.926479Z] 07:47:04     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Test timed out. 

Sean - do you know what is going wrong here?
Flags: needinfo?(selee)
I implemented test_password_field_autocomplete.html (bug 1317284), but I am not sure if it's relative to this one.

MattN, could you help to see this issue?
Flags: needinfo?(selee) → needinfo?(MattN+bmo)
I have no time to look into this for the next 2-3 weeks due to fixing stuff on beta and a team work week.
Matt, could you help find someone else to look at this issue so we could possibly resolve it in the next 2 weeks?
Attached patch disable the test temporarily (obsolete) — Splinter Review
lets disable this test until there is time or easier debugging.
Attachment #8841062 - Flags: review?(gbrown)
Keywords: leave-open
Whiteboard: [stockwell disabled]
Comment on attachment 8841062 [details] [diff] [review]
disable the test temporarily

Review of attachment 8841062 [details] [diff] [review]:
-----------------------------------------------------------------

::: toolkit/components/passwordmgr/test/mochitest/mochitest.ini
@@ +28,5 @@
>  [test_basic_form_3pw_1.html]
>  [test_basic_form_autocomplete.html]
>  skip-if = toolkit == 'android' # android:autocomplete.
>  [test_insecure_form_field_autocomplete.html]
> +skip-if = toolkit == 'android' && (os == 'linux' && debug) # android:autocomplete., linux: bug 1325778

The majority of failures are debug, but a significant percent are asan/opt/pgo...consider skipping on all linux.
Attachment #8841062 - Flags: review?(gbrown) → review+
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/506e2da5e26f
Intermittent toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html. r=gbrown
I had to back this out for turning the test permafail. Are you sure you meant "&&"?

https://hg.mozilla.org/mozilla-central/rev/e1135c6fdc9b
Flags: needinfo?(jmaher)
thanks KWierso, I will test a bit more, apologies for the confusion here.  Was this perma fail on android?
Yeah. Your patch changed the skip-if so that it will only skip the test if the toolkit is android AND we are on debug linux, which is probably never going to be true, causing it to run unskipped everywhere. You probably want
+skip-if = toolkit == 'android' || (os == 'linux' && debug) # android:autocomplete., linux: bug 1325778
which will skip if we are either on android OR we're on debug linux.
oh, this time I am doing the right thing here
Attachment #8841062 - Attachment is obsolete: true
Flags: needinfo?(jmaher)
Attachment #8842121 - Flags: review?(gbrown)
Comment on attachment 8842121 [details] [diff] [review]
disable the test temporarily

Review of attachment 8842121 [details] [diff] [review]:
-----------------------------------------------------------------

Yes, that's better. Sorry I didn't catch the earlier problem!
Attachment #8842121 - Flags: review?(gbrown) → review+
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/6b3ce92ad51e
Intermittent toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html. r=gbrown
this has increased on linux debug since April 8th, :mattn, do you have time to look at this, or should we disable a bit more?
This is supposed to be disabled on Linux. It seems like comment 26 disabled the wrong test?
Flags: needinfo?(MattN+bmo) → needinfo?(jmaher)
yeah, this confused me earlier and now I see it was the wrong test- lets enable the other test and disable the failing test!
Flags: needinfo?(jmaher)
Attachment #8858101 - Flags: review?(MattN+bmo)
Comment on attachment 8858101 [details] [diff] [review]
disable the correct test temporarily

Review of attachment 8858101 [details] [diff] [review]:
-----------------------------------------------------------------

Thanks
Attachment #8858101 - Flags: review?(MattN+bmo) → review+
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/18037527c4b8
Intermittent toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html. disable the right test. r=mattn

Over the last 7 days this bug has 32 failures. These happen on osx-10-10 and windows10-64.

Here is the most recent log example: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=222376013&repo=mozilla-inbound&lineNumber=32080

21:55:42 INFO - Resetting recipes
21:55:42 INFO - Buffered messages logged at 21:50:34
21:55:42 INFO - AddTask.js | Leaving test test_form11_recipes
21:55:42 INFO - AddTask.js | Entering test test_form12_formless
21:55:42 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 username is:
21:55:42 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 password is:
21:55:42 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 username is:
21:55:42 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 password is:
21:55:42 INFO - Buffered messages finished
21:55:42 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Test timed out.
21:55:42 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:7
21:55:42 INFO - reportError@SimpleTest/TestRunner.js:121:7
21:55:42 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
21:55:42 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:55:42 INFO - TestRunner.runTests/<@SimpleTest/TestRunner.js:381:9
21:55:42 INFO - promise callbackTestRunner.runTests@SimpleTest/TestRunner.js:368:50
21:55:42 INFO - RunSet.runtests@SimpleTest/setup.js:201:3
21:55:42 INFO - RunSet.runall@SimpleTest/setup.js:180:5
21:55:42 INFO - hookupTests@SimpleTest/setup.js:273:5
21:55:42 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
21:55:42 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
21:55:42 INFO - EventHandlerNonNull
getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3
21:55:42 INFO - hookup@SimpleTest/setup.js:253:5
21:55:42 INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&hideResultsTable=1&manifestFile=tests.json&dumpOutputDirectory=%2Fvar%2Ffolders%2Fds%2F1q186d153x5g4nvpstzzk9rw00000x%2FT&cleanupCrashes=true:11:1
21:55:43 INFO - GECKO(2265) | MEMORY STAT | vsize 4146MB | residentFast 171MB | heapAllocated 13MB
21:55:43 INFO - TEST-OK | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | took 318344ms

Flags: needinfo?(MattN+bmo)

This might get fixed by bug 1518094.

Assignee: nobody → MattN+bmo
Status: NEW → ASSIGNED
Flags: needinfo?(MattN+bmo)
Priority: -- → P1
Assignee: MattN+bmo → nobody
Status: ASSIGNED → NEW
Priority: P1 → P2

There are 29 total failures in the last 7 days and 76 total failures in the last 30 days, on osx and windows.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=231335429&repo=autoland&lineNumber=32040

21:27:38 INFO - TEST-START | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html
21:27:38 INFO - GECKO(2428) | ++DOMWINDOW == 18 (0x121110000) [pid = 2431] [serial = 127] [outer = 0x12110b800]
21:27:38 INFO - GECKO(2428) | [Parent 2428, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
21:27:38 INFO - GECKO(2428) | TEST-PASS | http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/parent_utils.js | Got autocomplete popup - [object XULPopupElement] == true
21:27:38 INFO - GECKO(2428) | [Parent 2428, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
21:27:38 INFO - GECKO(2428) | [Parent 2428, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
21:27:39 INFO - GECKO(2428) | [Parent 2428, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
21:27:39 INFO - GECKO(2428) | [Parent 2428, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
21:27:39 INFO - GECKO(2428) | [Parent 2428, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120

21:32:53 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 password is:
21:32:53 INFO - Buffered messages finished
21:32:53 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Test timed out.
21:32:53 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:18
21:32:53 INFO - reportError@SimpleTest/TestRunner.js:121:22
21:32:53 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
21:32:53 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:32:53 INFO - TestRunner.runTests/<@SimpleTest/TestRunner.js:381:20
21:32:53 INFO - promise callbackTestRunner.runTests@SimpleTest/TestRunner.js:368:50
21:32:53 INFO - RunSet.runtests@SimpleTest/setup.js:201:14
21:32:53 INFO - RunSet.runall@SimpleTest/setup.js:180:12
21:32:53 INFO - hookupTests@SimpleTest/setup.js:273:12
21:32:53 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
21:32:53 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
21:32:53 INFO - EventHandlerNonNull
getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3
21:32:53 INFO - hookup@SimpleTest/setup.js:253:5
21:32:53 INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&hideResultsTable=1&manifestFile=tests.json&dumpOutputDirectory=%2Fvar%2Ffolders%2Fgf%2Fnyx5ybq91rxct3w95tbxkpph00000x%2FT&cleanupCrashes=true:11:1
21:32:54 INFO - GECKO(2428) | MEMORY STAT | vsize 4092MB | residentFast 124MB | heapAllocated 13MB
21:32:54 INFO - TEST-OK | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | took 315454ms

Matthew, it appears that bug 1518094 did not fix the issue. Can you please take a look or assign someone?

Flags: needinfo?(MattN+bmo)
Whiteboard: [stockwell disabled] → [stockwell disabled][stockwell needswork:owner]
Flags: needinfo?(MattN+bmo)

Matthew are there any update here?

There are 26 total failures in the last 7 days on osx-10-10 debug and windows10-64 debug.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=234239662&repo=autoland&lineNumber=1651

21:49:06 INFO - TEST-START | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html
21:49:06 INFO - GECKO(1962) | ++DOMWINDOW == 7 (0x11fbf2400) [pid = 1967] [serial = 28] [outer = 0x12b7255c0]
21:49:07 INFO - GECKO(1962) | [Parent 1962, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
21:49:07 INFO - GECKO(1962) | TEST-PASS | http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/parent_utils.js | Got autocomplete popup - [object XULPopupElement] == true

21:54:07 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form11 password is: testpass10
21:54:07 INFO - Resetting recipes
21:54:07 INFO - AddTask.js | Leaving test test_form11_recipes
21:54:07 INFO - AddTask.js | Entering test test_form12_formless
21:54:07 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 username is:
21:54:07 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 password is:
21:54:07 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 username is:
21:54:07 INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Checking form12 password is:
21:54:07 INFO - Buffered messages finished
21:54:07 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | Test timed out.
21:54:07 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:18
21:54:07 INFO - reportError@SimpleTest/TestRunner.js:121:22
21:54:07 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
21:54:07 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:54:07 INFO - TestRunner.resetTests@SimpleTest/TestRunner.js:399:14
21:54:07 INFO - TestRunner.runNextTest@SimpleTest/TestRunner.js:485:22
21:54:07 INFO - TestRunner.testUnloaded@SimpleTest/TestRunner.js:681:20
21:54:07 INFO - @SimpleTest/iframe-between-tests.html:11:10
21:54:07 INFO - EventListener.handleEvent*@SimpleTest/iframe-between-tests.html:9:8
21:54:07 INFO - GECKO(1962) | Removing 1 popup notifications.
21:54:08 INFO - GECKO(1962) | MEMORY STAT | vsize 4111MB | residentFast 123MB | heapAllocated 12MB
21:54:08 INFO - TEST-OK | toolkit/components/passwordmgr/test/mochitest/test_insecure_form_field_autocomplete.html | took 301197ms

Flags: needinfo?(MattN+bmo)

I'm looking in to it.

I can't reproduce this, testing locally on OSX 10.14.4 on latest m-c tip. I used a debug artifact build and ran with mochitest --verify as well as --repeat 100. I suspect that it has to do with the number of items in the popup not matching what the test expects.

I'll attach a patch that will check the contents of the autocomplete popup.

Flags: needinfo?(jaws)
Assignee: nobody → jaws
Status: NEW → ASSIGNED
Pushed by mozilla@noorenberghe.ca:
https://hg.mozilla.org/integration/autoland/rev/3ca83116916b
Check that the contents of the autocomplete popup match the tests expectations. r=MattN

I think I have figured it out. The test now adds the logins dynamically, and the logins may not have propagated to the autocomplete immediately after being added. I have a PoC patch that waits for the autocomplete to start showing the login after being added before proceeding with the test.

Flags: needinfo?(jaws)
Attachment #9053827 - Attachment description: Bug 1325778 - Wait for the logins added later in the test to appear in autocomplete popups before proceeding with the test. r?MattN → Bug 1325778 - Wait for storage updates before proceeding with test. r?MattN
Flags: needinfo?(jaws)
Flags: needinfo?(MattN+bmo)
Pushed by jwein@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/e144f4d450c7
Wait for storage updates before proceeding with test. r=MattN
Flags: needinfo?(jaws)
Pushed by jwein@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4edd84663f95
Check that the contents of the autocomplete popup match the tests expectations. r=MattN
https://hg.mozilla.org/integration/autoland/rev/f0df19a1280a
Wait for storage updates before proceeding with test. r=MattN

Failures on this are down to 0.003 and 0.004 per push. I think we can mark this as FIXED now.

Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.