Closed
Bug 1271445
(gloda-autocomplete)
Opened 9 years ago
Closed 8 years ago
Gloda search crashes in debug build due to assertion failure: mSearchesOngoing > 0 and use of deprecated feature (see comment #10).
Categories
(MailNews Core :: Database, defect)
MailNews Core
Database
Tracking
(thunderbird49 wontfix, thunderbird50 wontfix, thunderbird51 fixed, thunderbird52+ fixed, thunderbird53 fixed)
RESOLVED
FIXED
Thunderbird 53.0
People
(Reporter: jorgk-bmo, Assigned: jorgk-bmo)
References
Details
Attachments
(1 file, 2 obsolete files)
4.19 KB,
patch
|
asuth
:
review+
|
Details | Diff | Splinter Review |
Gloda search crashes in debug build.
As it says.
Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch), at c:/mozilla-source/comm-central/mozilla/toolkit/components/autocomplete/nsAutoCompleteController.cpp:812
JS call stack:
0 ACGR_markCompleted(aCompleter = [object Object]) ["file:///C:/mozilla-source/comm-central/obj-i686-pc-mingw32/dist/bin/components/glautocomp.js":93]
this = [object Object]
1 ContactIdentityCompleter.prototype.onQueryCompleted(aCollection = [object Object]) ["file:///C:/mozilla-source/comm-central/obj-i686-pc-mingw32/dist/bin/components/glautocomp.js":325]
this = [object Object]
2 gloda_coll_onQueryCompleted() ["resource:///modules/gloda/collection.js":631]
this = [object Object]
3 QueryFromQueryResolver.onQueryCompleted(aCollection = [object Object]) ["resource:///modules/gloda/datastore.js":147]
this = [object Object]
4 gloda_ds_qfq_handleCompletion(aReason = 0) ["resource:///modules/gloda/datastore.js":385]
this = [object Object]
C++ code:
NS_IMETHODIMP
nsAutoCompleteController::OnSearchResult(nsIAutoCompleteSearch *aSearch, nsIAutoCompleteResult* aResult)
{
MOZ_ASSERT(mSearchesOngoing > 0 && mSearches.Contains(aSearch));
I wanted to play around with gloda, check the columns and the message view, but it crashes when I enter a search term.
Assignee | ||
Comment 1•9 years ago
|
||
This can be seen as a C-C Xpcshell test failure:
PROCESS | 420 | Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch), at c:/builds/moz2_slave/tb-c-cen-w32-d-000000000000000/build/mozilla/toolkit/components/autocomplete/nsAutoCompleteController.cpp:812
First seen here: Mon May 9, 19:56:39
https://treeherder.mozilla.org/#/jobs?repo=comm-central&revision=f845c406cebde33fccc49a3892ce5e5d83de9287
Summary: Gloda search crashes in debug build → Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch) - Gloda search crashes in debug build
Comment 2•9 years ago
|
||
Maybe bug 1271338 comment 17 ?
Comment 3•9 years ago
|
||
Might not have anything to do with gloda:
"CONSOLE_MESSAGE: (error) [JavaScript Error: "PlacesRemoteTabsAutocompleteProvider is not defined" {file: "resource://gre/components/UnifiedComplete.js" line: 1240}]
17:47:27 INFO - _matchRemoteTabs@resource://gre/components/UnifiedComplete.js:1240:9
Updated•9 years ago
|
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → DUPLICATE
Assignee | ||
Comment 5•9 years ago
|
||
Gloda search still crashes in debug build, as per comment #0.
On a local debug build I still crash when I try to use a gloda search. Doesn't crash on all searches but it crashes every time I enter a search term that triggers a list of auto-complete suggestions.
Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---
Comment 6•9 years ago
|
||
:-(
Severity: normal → major
status-thunderbird49:
--- → affected
status-thunderbird50:
--- → affected
tracking-thunderbird49:
--- → ?
tracking-thunderbird50:
--- → ?
Assignee | ||
Comment 7•9 years ago
|
||
Do you have a debug build to confirm the crash?
Assignee | ||
Comment 8•9 years ago
|
||
I finally got around to trying this on a 100% fresh compile.
The condition that triggers the assert here
https://dxr.mozilla.org/mozilla-central/source/toolkit/components/autocomplete/nsAutoCompleteController.cpp#812
is mSearchesOngoing > 0 since we get here with mSearchesOngoing==0.
The call stack indicates that this is called directly from JS and the JS stack is:
0 ACGR_addRows(aRows = [object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[
object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object O
bject],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[
object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object O
bject],[object Object],[object Object],[object Object],[object Object]) ["file:///C:/mozilla-source/comm-central/obj-i686-pc-mingw32/dist/bin/components/glautocomp.js":105]
this = [object Object]
1 ContactIdentityCompleter.prototype.onQueryCompleted(aCollection = [object Object]) ["file:///C:/mozilla-source/comm-central/obj-i686-pc-mingw32/dist/bin/components/glautocomp.js":324]
this = [object Object]
2 gloda_coll_onQueryCompleted() ["resource:///modules/gloda/collection.js":631]
this = [object Object]
3 QueryFromQueryResolver.onQueryCompleted(aCollection = [object Object]) ["resource:///modules/gloda/datastore.js":147]
this = [object Object]
4 gloda_coll_onQueryCompleted() ["resource:///modules/gloda/collection.js":631]
this = [object Object]
5 QueryFromQueryResolver.onQueryCompleted(aCollection = [object Object]) ["resource:///modules/gloda/datastore.js":147]
this = [object Object]
6 gloda_coll_onQueryCompleted() ["resource:///modules/gloda/collection.js":631]
this = [object Object]
7 QueryFromQueryResolver.onQueryCompleted(aCollection = [object Object]) ["resource:///modules/gloda/datastore.js":147]
this = [object Object]
8 gloda_ds_qfq_handleCompletion(aReason = 0) ["resource:///modules/gloda
So it gets called from here:
https://dxr.mozilla.org/comm-central/source/mailnews/db/gloda/components/glautocomp.js#105
Marco, would you be able to give me an idea how to debug this further?
Flags: needinfo?(mak77)
Comment 9•9 years ago
|
||
Usually that assertion means that you tried to append a new result after stopSearch has been invoked.
You may have a race condition there, maybe not sending _ONGOING result at the right time?
If you can reproduce 100% of the times, you should be able to check that with some dumping.
If this should become a real pain to debug, we can relax the MOZ_ASSERT to a non-fatal assertion.
Flags: needinfo?(mak77)
Assignee | ||
Comment 10•9 years ago
|
||
This is a real pain. Sometimes mSearchesOngoing is 0, sometimes it's not.
I've been playing with it for a while to see whether it can be reproduced reliably, but I didn't find a way.
Instead I got another assert:
Assertion failure: false (Passing new matches to OnSearchResult with a new nsIAutoCompleteResult every time is deprecated, please update the same result until the search is done), at c:/mozilla-source/comm-central/mozilla/toolkit/components/autocomplete/nsAutoCompleteController.cpp:1566
Maybe someone who knows about Gloda and autocomplete should look at this since I have no expertise in this area. I just noticed the crash when trying to use Gloda with a debug build.
Status: REOPENED → NEW
Flags: needinfo?(bugmail)
Summary: Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch) - Gloda search crashes in debug build → Gloda search crashes in debug build due to assertion failure: mSearchesOngoing > 0 and use of deprecated feature (see comment #10).
Comment 11•9 years ago
|
||
(In reply to Jorg K (GMT+2, PTO during summer, NI me) from comment #10)
> Instead I got another assert:
> Assertion failure: false (Passing new matches to OnSearchResult with a new
> nsIAutoCompleteResult every time is deprecated, please update the same
> result until the search is done)
oh yes, autocomplete supported 2 different ways to provide results:
1. either keep updating the same result object with new matches and set searchResult accordingly
2. or every time you have new matches, create a new result object and pass it
This was a pointless complication, so 2. has been deprecated (the code works internally by merging the multiple results into a single one and taking path 1.).
There may be a relation with the previous assertion, since this code path is deprecated it may contain race conditions we never fixed.
Comment 12•9 years ago
|
||
I would suggest adding (or turning on if available) some logging to discover what the additional search results being added late are, i.e. if they are expected or not.
Comment 13•9 years ago
|
||
Gloda autocomplete is very old; it implemented multiplexing of multiple parallel search results itself because autocomplete could not at the time. (Gloda may have even been using the pre-toolkit implementation.) Autocomplete has definitely been enhanced since then. It's probably easier to align it with the current idiom/flow than doing a lot of debugging of its current hacky use of the bindings.
I unfortunately am not available to assist in this endeavour for implementation or reviews.
Flags: needinfo?(bugmail)
Assignee | ||
Updated•8 years ago
|
Blocks: cc-backlog
Assignee | ||
Updated•8 years ago
|
Alias: gloda-autocomplete
Comment 14•8 years ago
|
||
Is this no longer showing up as an xpcshell failure because it got fixed along the way? I remember you or aceman touching gloda recently.
Flags: needinfo?(jorgk)
Assignee | ||
Comment 15•8 years ago
|
||
Right, it doesn't show in any test. But when you use Gloda in a debug build, the autocomplete regularly crashes, see comment #8. For further assessment read following comments, especially comment comment #11 and #13.
Basically, Golda autocomplete is broken, but no on has noticed it yet.
Flags: needinfo?(jorgk)
Comment 16•8 years ago
|
||
(In reply to Jorg K (GMT+2) from comment #15)
> Right, it doesn't show in any test.
I just wanted to confirm comment 1 is (now?) wrong.
I guess we should put this one on the fix-for-the-next-ESR list...
Updated•8 years ago
|
status-thunderbird51:
--- → affected
status-thunderbird52:
--- → affected
tracking-thunderbird51:
--- → ?
tracking-thunderbird52:
--- → ?
Comment 17•8 years ago
|
||
We've now had complaints about broken autocomplete in current aurora/beta.
Updated•8 years ago
|
Assignee | ||
Comment 18•8 years ago
|
||
Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch), at c:/mozilla-source/comm-central/mozilla/toolkit/components/autocomplete/nsAutoCompleteController.cpp:860
#01: XPTC__InvokebyIndex (c:\mozilla-source\comm-central\mozilla\xpcom\reflect\xptcall\md\win32\xptcinvoke_asm_x86_64.asm:99)
#02: CallMethodHelper::Call (c:\mozilla-source\comm-central\mozilla\js\xpconnect\src\xpcwrappednative.cpp:1385)
#03: XPCWrappedNative::CallMethod (c:\mozilla-source\comm-central\mozilla\js\xpconnect\src\xpcwrappednative.cpp:1350)
#04: XPC_WN_CallMethod (c:\mozilla-source\comm-central\mozilla\js\xpconnect\src\xpcwrappednativejsops.cpp:1143)
#05: js::CallJSNative (c:\mozilla-source\comm-central\mozilla\js\src\jscntxtinlines.h:239)
#06: js::InternalCallOrConstruct (c:\mozilla-source\comm-central\mozilla\js\src\vm\interpreter.cpp:459)
#07: Interpret (c:\mozilla-source\comm-central\mozilla\js\src\vm\interpreter.cpp:2922)
#08: js::RunScript (c:\mozilla-source\comm-central\mozilla\js\src\vm\interpreter.cpp:405)
#09: js::InternalCallOrConstruct (c:\mozilla-source\comm-central\mozilla\js\src\vm\interpreter.cpp:477)
#10: js::jit::DoCallFallback (c:\mozilla-source\comm-central\mozilla\js\src\jit\baselineic.cpp:6012)
#11: ??? (???:???)
0 ACGR_addRows(aRows = [object Object],[object Object]) ["file:///C:/mozilla-source/comm-central/obj-x86_64-pc-mingw32/dist/bin/components/glautocomp.js":105]
this = [object Object]
1 ContactIdentityCompleter.prototype.onQueryCompleted(aCollection = [object Object]) ["file:///C:/mozilla-source/comm-central/obj-x86_64-pc-mingw32/dist/bin/components/glautocomp.js":324]
this = [object Object]
2 gloda_coll_onQueryCompleted() ["resource:///modules/gloda/collection.js":631]
this = [object Object]
3 QueryFromQueryResolver.onQueryCompleted(aCollection = [object Object]) ["resource:///modules/gloda/datastore.js":147]
this = [object Object]
4 gloda_ds_qfq_handleCompletion(aReason = 0) ["resource:///modules/gloda/datastore.js":385]
this = [object Object]
Since there are no takers, I'll have to look at it myself. The crash is still there.
Assignee | ||
Comment 19•8 years ago
|
||
OK, I added some debug and there are two problems here.
The first is that results are added after stopSearch was called. That looks like this:
=== start search being called, term=hen
=== calling onSearchResult in announceYourself
=== OnSearchResult: mSearchesOngoing = 1
=== OnSearchResult: mSearches.Contains(aSearch) = true
=== stop search being called
=== calling onSearchResult in addRows
=== OnSearchResult: mSearchesOngoing = 0
=== OnSearchResult: mSearches.Contains(aSearch) = true
Assertion failure: mSearchesOngoing > 0 && mSearches.Contains(aSearch)
Marco predicted this in comment #9.
The second problem is that we pass new results in a new result object every time. That looks like this:
=== start search being called, term=hen
=== calling onSearchResult in announceYourself
=== OnSearchResult: mSearchesOngoing = 1
=== OnSearchResult: mSearches.Contains(aSearch) = true
=== stop search being called
=== start search being called, term=henk
=== calling onSearchResult in announceYourself
=== OnSearchResult: mSearchesOngoing = 1
=== OnSearchResult: mSearches.Contains(aSearch) = true
=== calling onSearchResult in addRows
=== OnSearchResult: mSearchesOngoing = 1
=== OnSearchResult: mSearches.Contains(aSearch) = true
Assertion failure: false (Passing new matches to OnSearchResult with a new nsIAutoCompleteResult every time is deprecated, please update the same result until the search is done), at c:/mozilla-source/comm-central/mozilla/toolkit/components/autocomplete/nsAutoCompleteController.cpp:1625
Marco mentioned this in comment #11.
Assignee | ||
Updated•8 years ago
|
status-firefox49:
affected → ---
status-thunderbird53:
--- → affected
tracking-thunderbird49:
? → ---
tracking-thunderbird50:
? → ---
tracking-thunderbird51:
? → ---
Assignee | ||
Comment 20•8 years ago
|
||
Gloda autocomplete results are derived asynchronously. That means that they arrive and get passed onto the autocomplete controller after it has already stopped the search. A simple gate suppresses late results so they don't get passed on. That fixed the first problem which doesn't always occur since it's timing related. I was lucky (or unlucky) to catch it a few times, the second time with the fix in place. That looks like this:
=== start search being called, term=hen
=== calling onSearchResult in announceYourself
=== OnSearchResult: mSearchesOngoing = 1
=== OnSearchResult: mSearches.Contains(aSearch) = true
=== stop search being called <<<<=== STOP!!
=== calling onSearchResult in addRows, searchActive=false <<<< results suppressed.
=== calling onSearchResult in markCompleted, searchActive=false <<<< results suppressed.
=== start search being called, term=henk
=== calling onSearchResult in announceYourself
=== OnSearchResult: mSearchesOngoing = 1
Now to the second problem of always delivering the results in the same object. I have the feeling that that just a different incarnation of the first problem. If the results arrive late, but another search has started, they will be delivered with the first object in the second search although they are no longer relevant. Let me try this.
Assignee: nobody → jorgk
Status: NEW → ASSIGNED
Assignee | ||
Comment 21•8 years ago
|
||
This works. A simple gate protects against
- sending late async results when search has stopped
- sending late async results to new search when previous
search has stopped and new one was started.
Andrew, you said you didn't want to participate in the fix or the review, but this solution is so dead-simple that you can review it in two minutes.
I ran it with additional debug and it clearly shows that both cases are fixed. It's hard to provoke it since you need the async results late so that the search has already stopped and even a new one has started. I hit both cases and they are both fixed.
Attachment #8814250 -
Attachment is obsolete: true
Attachment #8814256 -
Flags: review?(bugmail)
Assignee | ||
Comment 22•8 years ago
|
||
This is nicer since it doesn't use a global variable.
Attachment #8814256 -
Attachment is obsolete: true
Attachment #8814256 -
Flags: review?(bugmail)
Attachment #8814264 -
Flags: review?(bugmail)
Comment 23•8 years ago
|
||
Comment on attachment 8814264 [details] [diff] [review]
1271445-gloda-autocomplete.patch (v2).
Review of attachment 8814264 [details] [diff] [review]:
-----------------------------------------------------------------
Okay, but only because I'm a sucker for self-descriptive code and informative comments! :)
Excellent patch, thank you.
Attachment #8814264 -
Flags: review?(bugmail) → review+
Assignee | ||
Comment 24•8 years ago
|
||
Landed on trunk and branches:
C-C (TB 53): https://hg.mozilla.org/comm-central/rev/82f30d653e8a6e483aea2375b919571c4b253390
C-A (TB 52): https://hg.mozilla.org/releases/comm-aurora/rev/422cb090c018688a1df3c78312bed8a13af790f4
C-B (TB 51): https://hg.mozilla.org/releases/comm-beta/rev/063acd7aa29859208f0784b3b797263c6f304937
Status: ASSIGNED → RESOLVED
Closed: 9 years ago → 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 53.0
You need to log in
before you can comment on or make changes to this bug.
Description
•