Closed Bug 1454211 Opened 7 years ago Closed 4 years ago

Form Autofill/History Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch) in nsAutoCompleteController.cpp:821 - classify if failining test path contains "formautofill"

Categories

(Toolkit :: Form Autofill, enhancement, P3)

enhancement

Tracking

()

RESOLVED FIXED
94 Branch
Tracking Status
firefox94 --- fixed

People

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

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered][stockwell unknown])

Attachments

(3 files)

Filed by: ncsoregi [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=173736680&repo=mozilla-central https://queue.taskcluster.net/v1/task/B2UAOvHrSKy_c4f0EqZW_Q/runs/0/artifacts/public/logs/live_backing.log 01:25:25 INFO - GECKO(5136) | TEST-PASS | http://mochi.test:8888/tests/browser/extensions/formautofill/test/mochitest/parent_utils.js | Got autocomplete popup - [object XULElement] == true 01:25:25 INFO - GECKO(5136) | JavaScript error: jar:file:///Z:/task_1523754940/build/application/firefox/omni.ja!/components/mozIntl.js, line 211: TypeError: All region codes must be strings. 01:25:25 INFO - GECKO(5136) | [Parent 5136, Main Thread] WARNING: 'aRv.Failed()', file z:/build/build/src/dom/ipc/StructuredCloneData.cpp, line 123 01:25:25 INFO - GECKO(5136) | TEST-PASS | http://mochi.test:8888/tests/browser/extensions/formautofill/test/mochitest/formautofill_parent_utils.js | true == true 01:25:27 INFO - GECKO(5136) | --DOMWINDOW == 8 (000001C5AF735400) [pid = 5624] [serial = 13] [outer = 0000000000000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html] 01:25:27 INFO - GECKO(5136) | --DOMWINDOW == 7 (000001C5AF732400) [pid = 5624] [serial = 14] [outer = 0000000000000000] [url = http://mochi.test:8888/tests/browser/extensions/formautofill/test/mochitest/test_formautofill_preview_highlight.html] 01:25:28 INFO - GECKO(5136) | Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch), at z:/build/build/src/toolkit/components/autocomplete/nsAutoCompleteController.cpp:821 01:25:45 INFO - GECKO(5136) | #01: XPTC__InvokebyIndex [xpcom/reflect/xptcall/md/win32/xptcinvoke_asm_x86_64.asm:99] 01:25:45 INFO - GECKO(5136) | #02: CallMethodHelper::Call() [js/xpconnect/src/XPCWrappedNative.cpp:1267] 01:25:45 INFO - GECKO(5136) | #03: XPCWrappedNative::CallMethod(XPCCallContext &,XPCWrappedNative::CallMode) [js/xpconnect/src/XPCWrappedNative.cpp:1234] 01:25:45 INFO - GECKO(5136) | #04: XPC_WN_CallMethod(JSContext *,unsigned int,JS::Value *) [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:912] 01:25:45 INFO - GECKO(5136) | #05: js::CallJSNative(JSContext *,bool (*)(JSContext *,unsigned int,JS::Value *),JS::CallArgs const &) [js/src/vm/JSContext-inl.h:280] 01:25:45 INFO - GECKO(5136) | #06: js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [js/src/vm/Interpreter.cpp:467] 01:25:45 INFO - GECKO(5136) | #07: static bool InternalCall(struct JSContext *, const class js::AnyInvokeArgs & const) [js/src/vm/Interpreter.cpp:516] 01:25:45 INFO - GECKO(5136) | #08: static bool Interpret(struct JSContext *, class js::RunState & const) [js/src/vm/Interpreter.cpp:3084] 01:25:45 INFO - GECKO(5136) | #09: js::RunScript(JSContext *,js::RunState &) [js/src/vm/Interpreter.cpp:417] 01:25:45 INFO - GECKO(5136) | #10: js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [js/src/vm/Interpreter.cpp:489]
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → DUPLICATE

Bug 1358643 is about a different autocomplete consumer so they aren't dupes.

dholbert hit this in a local debug build in a new profile with the following STR:

  1. Launch firefox with --setpref signon.showAutoCompleteFooter=true --jsdebugger
  2. Visit https://wiki.mozilla.org/index.php?title=Special:UserLogin&returnto=Main+Page, couldn't get autocomplete dialog to appear, since this was a fresh profile and there was nothing to complete
  3. Type "abc" into the username field and hit 'enter' to submit
  4. Focused the username field on the login-failed-try-again page

Expected result:
No assertion failure

Actual result:
I saw a suggestion dropdown once or twice, and then got a content-process crash with that assertion failure (while clicking into & not-into that username field, IIRC)

Stack trace:

Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch), at /scratch/work/builds/mozilla-inbound/mozilla/toolkit/components/autocomplete/nsAutoCompleteController.cpp:794
#01: nsAutoCompleteController::OnSearchResult(nsIAutoCompleteSearch*, nsIAutoCompleteResult*) (/scratch/work/builds/mozilla-inbound/mozilla/toolkit/components/autocomplete/nsAutoCompleteController.cpp:794)
#02: nsFormFillController::OnSearchCompletion(nsIAutoCompleteResult*) (/scratch/work/builds/mozilla-inbound/obj/toolkit/components/satchel/../../../../mozilla/toolkit/components/satchel/nsFormFillController.cpp:791)
#03: NS_InvokeByIndex (/scratch/work/builds/mozilla-inbound/obj/xpcom/reflect/xptcall/md/unix/../../../../../../mozilla/xpcom/reflect/xptcall/md/unix/xptcinvoke_asm_x86_64_unix.S:110)
Status: RESOLVED → REOPENED
Has STR: --- → yes
Resolution: DUPLICATE → ---
Summary: Intermittent GECKO(5136) | Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch), at z:/build/build/src/toolkit/components/autocomplete/nsAutoCompleteController.cpp:821 → Form Autofill/History Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch) in nsAutoCompleteController.cpp:821
Status: REOPENED → NEW

I was only able to reproduce this once, BTW, so it seems to be a bit finicky.

Status: NEW → RESOLVED
Closed: 7 years ago6 years ago
Resolution: --- → INCOMPLETE
Summary: Form Autofill/History Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch) in nsAutoCompleteController.cpp:821 → Form Autofill/History Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch) in nsAutoCompleteController.cpp:821 - classify if failining test path contains "formautofill"

There are 92 total failures in the last 7 days on macosx1014-64 debug and windows7-32 debug.

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

[task 2019-07-26T20:58:36.292Z] 20:58:36 INFO - TEST-START | browser/extensions/formautofill/test/mochitest/test_basic_autocomplete_form.html
[task 2019-07-26T20:58:36.337Z] 20:58:36 INFO - [1741, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 664
[task 2019-07-26T20:58:36.372Z] 20:58:36 INFO - GECKO(1744) | ++DOMWINDOW == 11 (0x1212e8800) [pid = 1746] [serial = 17] [outer = 0x11e7423e0]
[task 2019-07-26T20:58:36.408Z] 20:58:36 INFO - GECKO(1744) | [Child 1746, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x80070057: file /builds/worker/workspace/build/src/toolkit/components/antitracking/AntiTrackingCommon.cpp, line 1857
[task 2019-07-26T20:58:36.430Z] 20:58:36 INFO - GECKO(1744) | [Child 1746, Main Thread] WARNING: NS_ENSURE_SUCCESS_VOID(rv) failed with result 0x80070057: file /builds/worker/workspace/build/src/toolkit/components/antitracking/AntiTrackingCommon.cpp, line 1857
[task 2019-07-26T20:58:36.430Z] 20:58:36 INFO - GECKO(1744) | [Parent 1744, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
[task 2019-07-26T20:58:36.498Z] 20:58:36 INFO - GECKO(1744) | --DOMWINDOW == 10 (0x11e7ecc00) [pid = 1746] [serial = 12] [outer = 0x0] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2019-07-26T20:58:36.498Z] 20:58:36 INFO - GECKO(1744) | --DOMWINDOW == 9 (0x11f4ed400) [pid = 1746] [serial = 11] [outer = 0x0] [url = http://mochi.test:8888/]
[task 2019-07-26T20:58:36.498Z] 20:58:36 INFO - GECKO(1744) | --DOMWINDOW == 8 (0x11f89ec00) [pid = 1746] [serial = 8] [outer = 0x0] [url = http://mochi.test:8888/tests/browser/extensions/formautofill/test/mochitest/test_address_level_1_submission.html]
[task 2019-07-26T20:58:36.968Z] 20:58:36 INFO - GECKO(1744) | [Parent 1744, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
[task 2019-07-26T20:58:36.968Z] 20:58:36 INFO - GECKO(1744) | [Parent 1744, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120
[task 2019-07-26T20:58:36.968Z] 20:58:36 INFO - GECKO(1744) | [Parent 1744, Main Thread] WARNING: 'aRv.Failed()', file /builds/worker/workspace/build/src/dom/ipc/StructuredCloneData.cpp, line 120

[task 2019-07-26T20:58:41.254Z] 20:58:41 INFO - TEST-OK | browser/extensions/formautofill/test/mochitest/test_basic_autocomplete_form.html | took 4963ms
[task 2019-07-26T20:58:41.310Z] 20:58:41 INFO - GECKO(1744) | ++DOMWINDOW == 7 (0x11f89b800) [pid = 1746] [serial = 18] [outer = 0x11e7423e0]
[task 2019-07-26T20:58:41.313Z] 20:58:41 INFO - GECKO(1744) | Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch), at /builds/worker/workspace/build/src/toolkit/components/autocomplete/nsAutoCompleteController.cpp:808
[task 2019-07-26T20:59:01.022Z] 20:59:01 INFO - GECKO(1744) | #01: non-virtual thunk to nsAutoCompleteController::OnSearchResult(nsIAutoCompleteSearch*, nsIAutoCompleteResult*) [toolkit/components/autocomplete/nsAutoCompleteController.cpp:0]
[task 2019-07-26T20:59:01.022Z] 20:59:01 INFO -
[task 2019-07-26T20:59:01.022Z] 20:59:01 INFO - GECKO(1744) | [Parent 1744, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/workspace/build/src/ipc/glue/ProtocolUtils.cpp, line 568
[task 2019-07-26T20:59:01.022Z] 20:59:01 INFO - GECKO(1744) | [Parent 1744, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/workspace/build/src/ipc/glue/ProtocolUtils.cpp, line 568
[task 2019-07-26T20:59:01.022Z] 20:59:01 INFO - GECKO(1744) | ++DOCSHELL 0x119024800 == 6 [pid = 1744] [id = {a52627dc-a11c-5d4d-acc9-efd4b7e258fa}]
[task 2019-07-26T20:59:01.022Z] 20:59:01 INFO - GECKO(1744) | ++DOMWINDOW == 11 (0x106d243e0) [pid = 1744] [serial = 12] [outer = 0x0]
[task 2019-07-26T20:59:01.022Z] 20:59:01 INFO - GECKO(1744) | ++DOMWINDOW == 12 (0x11a004800) [pid = 1744] [serial = 13] [outer = 0x106d243e0]
[task 2019-07-26T20:59:01.022Z] 20:59:01 ERROR - GECKO(1744) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2019-07-26T20:59:01.023Z] 20:59:01 INFO - GECKO(1744) | ++DOMWINDOW == 13 (0x123b2d000) [pid = 1744] [serial = 14] [outer = 0x106d243e0]
[task 2019-07-26T20:59:01.023Z] 20:59:01 INFO - GECKO(1744) | [Child 1745, Main Thread] WARNING: nsAppShell::Exit() called redundantly: file /builds/worker/workspace/build/src/widget/cocoa/nsAppShell.mm, line 725
[task 2019-07-26T20:59:01.023Z] 20:59:01 INFO - GECKO(1744) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost

Matthew can you please assign someone? Failure rate is pretty high.

Flags: needinfo?(MattN+bmo)
Whiteboard: [retriggered] → [retriggered][stockwell needswork:owner]
Pushed by nerli@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/2d6b54af1b07 Disable test test_basic_autocomplete_form.html on windows and macos r=aryx
Keywords: leave-open
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered][stockwell disabled]
Flags: needinfo?(MattN+bmo)
Priority: P5 → P2
Severity: normal → S3
Type: defect → enhancement
Priority: P2 → P3

Probably not, my change would only have an effect with fission and fission is not activated in those tests. I did some retriggers and there is a push in that link now that touches android code that has failures of this type but no previous push does.

Flags: needinfo?(tnikkel)
Whiteboard: [retriggered][stockwell disabled] → [retriggered][stockwell disabled][stockwell needswork:owner]

Dimi, is this something that someone in your team can take a look at? I'm not sure what is happening here. I added more logging in this try run: https://treeherder.mozilla.org/jobs?repo=try&revision=2b0f74a0e6849815535e52ef095900f34831a27f&selectedTaskRun=BXboOJEUQ6GREcsNegunPA.0 and from what I can tell the code that is throwin the assertion doesn't run at all for successful test runs, but I'm not sure why. E.g. this is the log for a successful test run: https://paste.mozilla.org/24KKSsg8 (you can see there's no sferrog: logs in there).

Flags: needinfo?(agi) → needinfo?(dlee)

(In reply to Agi Sferro | :agi | ni? for questions | ⏰ PST | he/him from comment #61)

Dimi, is this something that someone in your team can take a look at? I'm not sure what is happening here. I added more logging in this try run:

Sure, I'll take a look at this one.

While calling StopSearch(), we only stop either seaches triggered by
formautofill or the password manager, but not both. So when there are both an ongoing
formautofill search and login manager search, the search from the login
manager is not canceled, which messes up the internal state of nsFormFillController.

Assignee: nobody → dlee
Status: REOPENED → ASSIGNED
Flags: needinfo?(dlee)
Pushed by dlee@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/f59a0106165d nsFormFillController StopSearch() should stop searches from both login manager and formautofill r=sfoster,tgiles

Looks like this bug is fixed! I'll close the bug!

Status: ASSIGNED → RESOLVED
Closed: 6 years ago4 years ago
Resolution: --- → FIXED

Dimi: should we re-enable test_basic_autocomplete_form.html? It was disabled a while back, comment 27.

Flags: needinfo?(dlee)
Target Milestone: --- → 94 Branch

(In reply to Andreea Pavel [:apavel] from comment #73)

Dimi: should we re-enable test_basic_autocomplete_form.html? It was disabled a while back, comment 27.

I'm not 100% sure if my patch also fixes the issue on those platforms, but yes, let's re-enable the test and see what will happen.

Flags: needinfo?(dlee)
Pushed by dlee@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/00a0fa299768 Re-enable test_basic_autocomplete_form.html test on Windowns and Mac r=tgiles
Whiteboard: [retriggered][stockwell disabled][stockwell needswork:owner] → [retriggered][stockwell needswork:owner]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: