Closed Bug 1833987 Opened 10 months ago Closed 10 months ago

High frequency Win toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking form-basic username is: name1 - "" == "name1" - got "", expected "name1" (operator ==)

Categories

(Toolkit :: Password Manager, defect, P5)

defect

Tracking

()

RESOLVED FIXED
116 Branch
Tracking Status
firefox115 --- fixed
firefox116 --- fixed

People

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

Details

(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [stockwell disable-recommended])

Attachments

(1 file)

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=416329932&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FCbMcij-Qh-MKu3nsz39CQ/runs/0/artifacts/public/logs/live_backing.log


[task 2023-05-19T02:14:15.550Z] 02:14:15     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking for no disabled hosts - 0 == 0 
[task 2023-05-19T02:14:15.550Z] 02:14:15     INFO - add_task | Entering test_autocomplete_https_downgrade
[task 2023-05-19T02:14:15.550Z] 02:14:15     INFO - test_autocomplete_http, setup with http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/form_basic.html
[task 2023-05-19T02:14:15.550Z] 02:14:15     INFO - got logins: ,,,
[task 2023-05-19T02:14:15.550Z] 02:14:15     INFO - Buffered messages finished
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking form-basic username is: name1 - "" == "name1" - got "", expected "name1" (operator ==)
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - @http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/pwmgr_common.js:344:14
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - execute@resource://specialpowers/SpecialPowersSandbox.sys.mjs:139:12
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - _spawnTask@resource://specialpowers/SpecialPowersChild.sys.mjs:1648:15
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - receiveMessage@resource://specialpowers/SpecialPowersChild.sys.mjs:261:21
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - JSActor query*receiveMessage@resource://specialpowers/SpecialPowersParent.sys.mjs:1388:14
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - JSActor query*spawn@resource://specialpowers/SpecialPowersChild.sys.mjs:1579:17
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - doApply@resource://specialpowers/WrapPrivileged.sys.mjs:117:18
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - apply/<@resource://specialpowers/WrapPrivileged.sys.mjs:252:30
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - wrapExceptions@resource://specialpowers/WrapPrivileged.sys.mjs:205:12
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - apply@resource://specialpowers/WrapPrivileged.sys.mjs:236:12
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - checkLoginFormInFrame@http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/pwmgr_common.js:326:24
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - test_autocomplete_https_downgrade@http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html:90:9
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - async*add_task/nextTick/<@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2143:34
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - nextTick@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2178:11
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - setTimeout handler*SimpleTest_setTimeoutShim@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:920:41
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - add_task@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2092:17
[task 2023-05-19T02:14:15.552Z] 02:14:15     INFO - @http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html:72:9
[task 2023-05-19T02:14:15.553Z] 02:14:15     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-05-19T02:14:15.555Z] 02:14:15     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking form-basic password is: pass1 - "" == "pass1" - got "", expected "pass1" (operator ==)
[task 2023-05-19T02:14:15.555Z] 02:14:15     INFO - @http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/pwmgr_common.js:349:14
[task 2023-05-19T02:14:15.555Z] 02:14:15     INFO - execute@resource://specialpowers/SpecialPowersSandbox.sys.mjs:139:12
[task 2023-05-19T02:14:15.556Z] 02:14:15     INFO - _spawnTask@resource://specialpowers/SpecialPowersChild.sys.mjs:1648:15
[task 2023-05-19T02:14:15.556Z] 02:14:15     INFO - receiveMessage@resource://specialpowers/SpecialPowersChild.sys.mjs:261:21
[task 2023-05-19T02:14:15.557Z] 02:14:15     INFO - JSActor query*receiveMessage@resource://specialpowers/SpecialPowersParent.sys.mjs:1388:14
[task 2023-05-19T02:14:15.557Z] 02:14:15     INFO - JSActor query*spawn@resource://specialpowers/SpecialPowersChild.sys.mjs:1579:17
[task 2023-05-19T02:14:15.557Z] 02:14:15     INFO - doApply@resource://specialpowers/WrapPrivileged.sys.mjs:117:18
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - apply/<@resource://specialpowers/WrapPrivileged.sys.mjs:252:30
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - wrapExceptions@resource://specialpowers/WrapPrivileged.sys.mjs:205:12
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - apply@resource://specialpowers/WrapPrivileged.sys.mjs:236:12
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - checkLoginFormInFrame@http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/pwmgr_common.js:326:24
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - test_autocomplete_https_downgrade@http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html:90:9
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - async*add_task/nextTick/<@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2143:34
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - nextTick@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2178:11
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - setTimeout handler*SimpleTest_setTimeoutShim@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:920:41
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - add_task@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2092:17
[task 2023-05-19T02:14:15.558Z] 02:14:15     INFO - @http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html:72:9
[task 2023-05-19T02:14:15.559Z] 02:14:15     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Check popup is initially closed 

This spiked in timeouts after disabling test_autocomplete_basic_form_insecure.html as I explained in https://bugzilla.mozilla.org/show_bug.cgi?id=1781648#c55 . Further disabling this one will most likely lead to another test in the manifest to timeout.

Update - in the past 7 days we had 108 failures:

  • windows11-32-2009-qr opt and debug
  • windows11-32-2009-shippable-qr opt
  • windows11-64-2009-asan-qr opt
  • windows11-64-2009-ccov-qr opt
  • windows11-64-2009-qr opt and debug
  • windows11-64-2009-shippable-qr opt

Most recent failure log: https://treeherder.mozilla.org/logviewer?job_id=417515599&repo=autoland&lineNumber=11661

[task 2023-05-30T16:02:38.751Z] 16:02:38     INFO - GECKO(3540) | JavaScript error: resource://gre/modules/XULStore.sys.mjs, line 60: Error: Can't find profile directory.
[task 2023-05-30T16:02:39.426Z] 16:02:39     INFO - TEST-INFO | started process screenshot
[task 2023-05-30T16:02:39.504Z] 16:02:39     INFO - TEST-INFO | screenshot: exit 0
[task 2023-05-30T16:02:39.508Z] 16:02:39     INFO - Buffered messages logged at 16:02:39
[task 2023-05-30T16:02:39.509Z] 16:02:39     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Got autocomplete popup - {"mInput":null,"mPopupOpen":false,"_currentIndex":0,"_disabledItemClicked":false} == true 
[task 2023-05-30T16:02:39.509Z] 16:02:39     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Access LoginManager - true == true 
[task 2023-05-30T16:02:39.510Z] 16:02:39     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Not expecting logins to be present - 0 == 0 
[task 2023-05-30T16:02:39.511Z] 16:02:39     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking for successful init login - 0 == 0 
[task 2023-05-30T16:02:39.511Z] 16:02:39     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking for no disabled hosts - 0 == 0 
[task 2023-05-30T16:02:39.512Z] 16:02:39     INFO - add_task | Entering test_autocomplete_https_downgrade
[task 2023-05-30T16:02:39.512Z] 16:02:39     INFO - test_autocomplete_http, setup with http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/form_basic.html
[task 2023-05-30T16:02:39.513Z] 16:02:39     INFO - got logins: ,,,
[task 2023-05-30T16:02:39.513Z] 16:02:39     INFO - Buffered messages finished
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking form-basic username is: name1 - "" == "name1" - got "", expected "name1" (operator ==)
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - @http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/pwmgr_common.js:340:14
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - execute@resource://testing-common/SpecialPowersSandbox.sys.mjs:139:12
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - _spawnTask@resource://testing-common/SpecialPowersChild.sys.mjs:1656:15
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - receiveMessage@resource://testing-common/SpecialPowersChild.sys.mjs:263:21
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - JSActor query*receiveMessage@resource://testing-common/SpecialPowersParent.sys.mjs:1400:14
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - JSActor query*spawn@resource://testing-common/SpecialPowersChild.sys.mjs:1585:17
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - doApply@resource://testing-common/WrapPrivileged.sys.mjs:117:18
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - apply/<@resource://testing-common/WrapPrivileged.sys.mjs:252:30
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - wrapExceptions@resource://testing-common/WrapPrivileged.sys.mjs:205:12
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - apply@resource://testing-common/WrapPrivileged.sys.mjs:236:12
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - checkLoginFormInFrame@http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/pwmgr_common.js:324:24
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - test_autocomplete_https_downgrade@http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html:90:9
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - async*add_task/nextTick/<@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2147:34
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - nextTick@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2182:11
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - setTimeout handler*SimpleTest_setTimeoutShim@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:920:41
[task 2023-05-30T16:02:39.517Z] 16:02:39     INFO - add_task@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2096:17
[task 2023-05-30T16:02:39.518Z] 16:02:39     INFO - @http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html:72:9
[task 2023-05-30T16:02:39.518Z] 16:02:39     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-05-30T16:02:39.522Z] 16:02:39     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking form-basic password is: pass1 - "" == "pass1" - got "", expected "pass1" (operator ==)
[task 2023-05-30T16:02:39.522Z] 16:02:39     INFO - @http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/pwmgr_common.js:345:14
[task 2023-05-30T16:02:39.522Z] 16:02:39     INFO - execute@resource://testing-common/SpecialPowersSandbox.sys.mjs:139:12
[task 2023-05-30T16:02:39.522Z] 16:02:39     INFO - _spawnTask@resource://testing-common/SpecialPowersChild.sys.mjs:1656:15
[task 2023-05-30T16:02:39.522Z] 16:02:39     INFO - receiveMessage@resource://testing-common/SpecialPowersChild.sys.mjs:263:21
[task 2023-05-30T16:02:39.522Z] 16:02:39     INFO - JSActor query*receiveMessage@resource://testing-common/SpecialPowersParent.sys.mjs:1400:14
[task 2023-05-30T16:02:39.523Z] 16:02:39     INFO - JSActor query*spawn@resource://testing-common/SpecialPowersChild.sys.mjs:1585:17
[task 2023-05-30T16:02:39.523Z] 16:02:39     INFO - doApply@resource://testing-common/WrapPrivileged.sys.mjs:117:18
[task 2023-05-30T16:02:39.523Z] 16:02:39     INFO - apply/<@resource://testing-common/WrapPrivileged.sys.mjs:252:30
[task 2023-05-30T16:02:39.523Z] 16:02:39     INFO - wrapExceptions@resource://testing-common/WrapPrivileged.sys.mjs:205:12
[task 2023-05-30T16:02:39.523Z] 16:02:39     INFO - apply@resource://testing-common/WrapPrivileged.sys.mjs:236:12
[task 2023-05-30T16:02:39.523Z] 16:02:39     INFO - checkLoginFormInFrame@http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/pwmgr_common.js:324:24
[task 2023-05-30T16:02:39.524Z] 16:02:39     INFO - test_autocomplete_https_downgrade@http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html:90:9
[task 2023-05-30T16:02:39.524Z] 16:02:39     INFO - async*add_task/nextTick/<@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2147:34
[task 2023-05-30T16:02:39.524Z] 16:02:39     INFO - nextTick@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2182:11
[task 2023-05-30T16:02:39.524Z] 16:02:39     INFO - setTimeout handler*SimpleTest_setTimeoutShim@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:920:41
[task 2023-05-30T16:02:39.524Z] 16:02:39     INFO - add_task@http://mochi.test:8888/tests/SimpleTest/SimpleTest.js:2096:17
[task 2023-05-30T16:02:39.524Z] 16:02:39     INFO - @http://mochi.test:8888/tests/toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html:72:9
[task 2023-05-30T16:02:39.524Z] 16:02:39     INFO - TEST-PASS | toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Check popup is initially closed 
[task 2023-05-30T16:02:39.524Z] 16:02:39     INFO - GECKO(3540) | JavaScript error: resource://services-settings/RemoteSettingsClient.sys.mjs, line 323: Error: Cannot instantiate Remote Settings client in child processes.```
Whiteboard: [stockwell needswork:owner]
Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]
Attachment #9337237 - Attachment description: WIP: Bug 1833987 - fix intermittent test_autocomplete_https_downgrade.html et al - r?#credential-management-reviewers! → WIP: Bug 1833987 - fix more intermittent tests - r?#credential-management-reviewers!
Assignee: nobody → joschmidt
Attachment #9337237 - Attachment description: WIP: Bug 1833987 - fix more intermittent tests - r?#credential-management-reviewers! → Bug 1833987 - fix more intermittent tests - r?#credential-management-reviewers!
Status: NEW → ASSIGNED
Summary: Intermittent toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | single tracking bug → High frequency Win toolkit/components/passwordmgr/test/mochitest/test_autocomplete_https_downgrade.html | Checking form-basic username is: name1 - "" == "name1" - got "", expected "name1" (operator ==)
Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]
Pushed by joschmidt@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/c7b58ffeb92b
fix more intermittent tests - r=credential-management-reviewers,dimi
Flags: needinfo?(joschmidt)

Are you sure the failure is cause by this change? Because there is https://bugzilla.mozilla.org/show_bug.cgi?id=1777035

Flags: needinfo?(joschmidt)

(In reply to Johannes from comment #20)

Are you sure the failure is cause by this change? Because there is https://bugzilla.mozilla.org/show_bug.cgi?id=1777035

I think you are right. I see an uptick in failures from bug 1777035.
I will reland your patch and monitor it more carefully in the upcoming days.
Thank you for looking and sorry.

Cool thank you! I will have a deeper look at the failure in the meantime.

Pushed by smolnar@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/256876c3862b
fix more intermittent tests - r=credential-management-reviewers,dimi CLOSED TREE
Status: ASSIGNED → RESOLVED
Closed: 10 months ago
Resolution: --- → FIXED
Target Milestone: --- → 116 Branch
You need to log in before you can comment on or make changes to this bug.