The default bug view has changed. See this FAQ.
Bug 1271445 (gloda-autocomplete)

Gloda search crashes in debug build due to assertion failure: mSearchesOngoing > 0 and use of deprecated feature (see comment #10).

RESOLVED FIXED in Thunderbird 53.0

Status

MailNews Core
Database
--
major
RESOLVED FIXED
11 months ago
4 months ago

People

(Reporter: Jorg K (GMT+1), Assigned: Jorg K (GMT+1))

Tracking

(Blocks: 1 bug)

Trunk
Thunderbird 53.0
Dependency tree / graph

Thunderbird Tracking Flags

(thunderbird49 wontfix, thunderbird50 wontfix, thunderbird51 fixed, thunderbird52+ fixed, thunderbird53 fixed)

Details

Attachments

(1 attachment, 2 obsolete attachments)

(Assignee)

Description

11 months ago
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

11 months 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

Updated

11 months ago
Blocks: 1272322

Comment 2

11 months ago
Maybe bug 1271338 comment 17 ?

Comment 3

10 months 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

10 months ago
No longer blocks: 1272322

Updated

10 months ago
Depends on: 1272322

Updated

10 months ago
Status: NEW → RESOLVED
Last Resolved: 10 months ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1272322
(Assignee)

Comment 5

10 months 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

10 months ago
:-(
Severity: normal → major
status-thunderbird49: --- → affected
status-thunderbird50: --- → affected
tracking-thunderbird49: --- → ?
tracking-thunderbird50: --- → ?
(Assignee)

Comment 7

10 months ago
Do you have a debug build to confirm the crash?
(Assignee)

Comment 8

9 months 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 months 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 months 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).
(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 months 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.
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

7 months ago
Blocks: 1054354
(Assignee)

Updated

7 months ago
Alias: gloda-autocomplete

Comment 14

6 months 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

6 months 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

6 months 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

6 months ago
status-thunderbird51: --- → affected
status-thunderbird52: --- → affected
tracking-thunderbird51: --- → ?
tracking-thunderbird52: --- → ?

Comment 17

5 months ago
We've now had complaints about broken autocomplete in current aurora/beta.

Updated

5 months ago
tracking-thunderbird52: ? → +
(Assignee)

Comment 18

4 months 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

4 months 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

4 months ago
status-firefox49: affected → ---
status-thunderbird49: affected → wontfix
status-thunderbird50: affected → wontfix
status-thunderbird53: --- → affected
tracking-thunderbird49: ? → ---
tracking-thunderbird50: ? → ---
tracking-thunderbird51: ? → ---
(Assignee)

Comment 20

4 months ago
Created attachment 8814250 [details] [diff] [review]
WIP: 1271445-gloda-autocomplete.patch (v1).

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

4 months ago
Created attachment 8814256 [details] [diff] [review]
1271445-gloda-autocomplete.patch

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

4 months ago
Created attachment 8814264 [details] [diff] [review]
1271445-gloda-autocomplete.patch (v2).

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 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

4 months 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
Last Resolved: 10 months ago4 months ago
status-thunderbird51: affected → fixed
status-thunderbird52: affected → fixed
status-thunderbird53: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 53.0
You need to log in before you can comment on or make changes to this bug.