Gloda: Activity "Indexing messages" still hanging in activity manager (fallout from bug 1292569)

VERIFIED FIXED in Thunderbird 51.0

Status

defect
VERIFIED FIXED
3 years ago
2 years ago

People

(Reporter: jorgk, Assigned: aceman)

Tracking

(Depends on 1 bug, {regression})

Trunk
Thunderbird 51.0
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment, 2 obsolete attachments)

Reporter

Description

3 years ago
Gloda: Activity "Indexing messages" still hanging in activity manager (fallout from bug 1292569)

As reported in bug 1292569 comment #30:
===
I'm using Gloda only one single folder, the folder where I move my BMO mail. After starting TB 51 and looking in the activity manager, this hangs with: Indexing messages, Determining which messages to index.
===

This has become better from when it was first reported: Sometimes the activity is not in the activity manager, sometimes it hangs there and sometimes closing TB and starting it again will fix it. So there is still something wrong.

Updated

3 years ago
Blocks: 1292569
Keywords: regression
Reporter

Comment 1

3 years ago
It happened again but this time I was smart enough to check the error console ;-)

TypeError: this.activeIterator.return is not a function [Learn More] indexer.js:897:7
https://dxr.mozilla.org/comm-central/rev/acfd5b90dcc9152d952d451ee08681f8900042b5/mailnews/db/gloda/modules/indexer.js#897

https://hg.mozilla.org/comm-central/diff/378b9a66d495/mailnews/db/gloda/modules/indexer.js#l1.45

Aceman, looks like .close() wasn't right, but .return() isn't right either, hmm.

Note: Bug 1292569 comment #31.
Flags: needinfo?(acelists)
Reporter

Comment 2

3 years ago
.close() to .return() changes to reconsider:

https://hg.mozilla.org/comm-central/rev/378b9a66d495#l20.22
https://hg.mozilla.org/comm-central/rev/378b9a66d495#l20.44 <== this one is causing trouble here.
https://hg.mozilla.org/comm-central/rev/378b9a66d495#l7.12 (.close()/.return() restored from first patch)
https://hg.mozilla.org/comm-central/rev/7b9fbef870b2#l12.12 (maybe mistakenly removed here).
Assignee

Comment 3

3 years ago
Can this.activeIterator just be null in this case? OR maybe some other object than expected. Can you dump it before the .return() call?
Flags: needinfo?(acelists)
Reporter

Comment 4

3 years ago
Posted patch How about this? (obsolete) — Splinter Review
Would it be correct to just remove the offending call?
.close() caused errors, and so does .return(). Maybe .close() was wrong in the first place, but JS didn't complain until bug 1199296.
I really have no idea, I must admit, but using Daily, this problem is a little annoying ;-(

Note, there is still:
https://dxr.mozilla.org/comm-central/rev/acfd5b90dcc9152d952d451ee08681f8900042b5/mailnews/db/gloda/modules/indexer.js#829
Attachment #8781122 - Flags: review?(bugmail)
Reporter

Comment 5

3 years ago
(In reply to :aceman from comment #3)
> Can this.activeIterator just be null in this case? OR maybe some other
> object than expected. Can you dump it before the .return() call?
Wouldn't there be a different error if it were null?

This error only shows up occasionally so I'd have to run with a debug build or manipulate my omni.ja to dump it out. Perhaps the original author can tell us something about it ;-)
Assignee

Comment 6

3 years ago
Comment on attachment 8781122 [details] [diff] [review]
How about this?

I don't know how useful it is to close (return) a generator. Maybe to remove it from memory or a safety measure so that you do not try to pull values from it again (what would be a logic error in the program). But simply not closing it should not have any negative effect.

I can try to run debug build with gloda on.
Comment on attachment 8781122 [details] [diff] [review]
How about this?

I'm not sure I really understand what's going on here either.  If you are interested in debugging what's going on, I'd probably do something like:

if (typeof(this.activeIterator) !== "function") {
  console.log("weird this.activeIterator:", this.activeIterator);
}

I'd probably also put it in the "push" method too, possibly with a "debugger" statement or an explicit throw so that you can get a callstack.

Having said that, I agree with :aceman that there isn't actually any need to be calling return() and that removing the line will not break anything further.  However, I do think that whatever is breaking here means something else is broken somewhere else, so I would advise trying to investigate a little more if you can.

(I'm assuming the gloda xpcshell tests still pass.  If they do, then things are probably sufficiently fine, unless the problem is in the chat indexer stuff in https://dxr.mozilla.org/comm-central/source/mail/components/im/modules/index_im.js which I don't think the main gloda tests use?)
Attachment #8781122 - Flags: review?(bugmail) → review+
Reporter

Comment 8

3 years ago
Posted patch Debug patch - no good. (obsolete) — Splinter Review
No success with this debug patch.
The 'typeof' is 'object' and I can't get the details of this object.
As mentioned, I also don't know how to trigger the erroneous condition. Sometimes when I visit the activity manager I get a large bar from left to right which doesn't want to disappear. Other times it tells me that it indexed nn messages in folder xx.
Reporter

Comment 9

3 years ago
Aceman, can you give me a hand here or shall I just land the patch?
Flags: needinfo?(acelists)
Assignee

Comment 10

3 years ago
You can also try:
1. this.activeIterator.toSource()
2. Object.keys(this.activeIterator)
Flags: needinfo?(acelists)
Reporter

Comment 11

3 years ago
None of this actually prints anything useful. BTW, the question was:

(In reply to Jorg K (GMT+2, PTO during summer) from comment #9)
> Aceman, can you give me a hand here or shall I just land the patch?
Flags: needinfo?(acelists)
Assignee

Comment 12

3 years ago
I'm still trying option 1 for now :)

Arai, do you have any new idea how to debug a generator?
Flags: needinfo?(acelists) → needinfo?(arai.unmht)
(In reply to :aceman from comment #12)
> I'm still trying option 1 for now :)
> 
> Arai, do you have any new idea how to debug a generator?

It should be quicker to just trace what's passed to the `push` method as `aIterator` parameter.


https://dxr.mozilla.org/comm-central/rev/e3a88b8c91e2267ace82651ec29049f1f451aaca/mailnews/db/gloda/modules/indexer.js#876
>   _callbackHandle: {
> ...
>     push: function gloda_index_callbackhandle_push(aIterator, aContext) {
>       this.activeStack.push(aIterator);
>       this.contextStack.push(aContext);
>       this.activeIterator = aIterator;
>     },

https://dxr.mozilla.org/comm-central/rev/e3a88b8c91e2267ace82651ec29049f1f451aaca/mailnews/db/gloda/modules/indexer.js#1293
>   _hireJobWorker: function gloda_index_hireJobWorker() {
> ...
>     let generator = null;
> 
>     if (job.jobType in this._indexerWorkerDefs) {
>       let workerDef = this._indexerWorkerDefs[job.jobType];
> ...
>       generator = workerDef.worker.call(workerDef.indexer, job,
>                                         this._callbackHandle);
>     }
> ...
>     if (generator) {
>       this._callbackHandle.push(generator);
>       return true;
>     }

https://dxr.mozilla.org/comm-central/rev/e3a88b8c91e2267ace82651ec29049f1f451aaca/mailnews/db/gloda/modules/indexer.js#459
>   registerIndexer: function gloda_index_registerIndexer(aIndexer) {
> ...
>       for (let workerInfo of aIndexer.workers) {
>         let workerCode = workerInfo[0];
>         let workerDef = workerInfo[1];
>         workerDef.name = workerCode;
>         workerDef.indexer = aIndexer;
>         this._indexerWorkerDefs[workerCode] = workerDef;

https://dxr.mozilla.org/comm-central/rev/e3a88b8c91e2267ace82651ec29049f1f451aaca/mailnews/db/gloda/modules/index_ab.js#121
> var GlodaABIndexer = {
> ...
>   get workers() {
>     return [
>       ["ab-card", {
>          worker: this._worker_index_card,
>        }],
>     ];
>   },
> ...
> };
> GlodaIndexer.registerIndexer(GlodaABIndexer);

https://dxr.mozilla.org/comm-central/rev/e3a88b8c91e2267ace82651ec29049f1f451aaca/mail/components/im/modules/index_im.js#712
> var GlodaIMIndexer = {
> ...
>   get workers() {
>     return [
>       ["indexIMConversation", {
>          worker: this._worker_indexIMConversation
>        }],
>       ["logsFolderSweep", {
>          worker: this._worker_logsFolderSweep
>        }],
>       ["convFolderSweep", {
>          worker: this._worker_convFolderSweep
>        }]
>     ];
>   },
> ...
> };
> 
> GlodaIndexer.registerIndexer(GlodaIMIndexer);


There, the following 2 functions are not ES6 generator.
(latter is even not a generator...)

https://dxr.mozilla.org/comm-central/rev/e3a88b8c91e2267ace82651ec29049f1f451aaca/mailnews/db/gloda/modules/index_ab.js#49
>   _worker_index_card: function(aJob, aCallbackHandle) {
>     let card = aJob.id;
> 
>     if (card.primaryEmail) {
>       // load the identity
>       let query = Gloda.newQuery(Gloda.NOUN_IDENTITY);
>       query.kind("email");
>       // we currently normalize all e-mail addresses to be lowercase
>       query.value(card.primaryEmail.toLowerCase());
>       let identityCollection = query.getCollection(aCallbackHandle);
>       yield Gloda.kWorkAsync;
> 
>       if (identityCollection.items.length) {
>         let identity = identityCollection.items[0];
>         // force the identity to know it has an associated ab card.
>         identity._hasAddressBookCard = true;
> 
>         this._log.debug("Found identity, processing card.");
>         yield aCallbackHandle.pushAndGo(
>             Gloda.grokNounItem(identity.contact, {card: card}, false, false,
>                                aCallbackHandle));
>         this._log.debug("Done processing card.");
>       }
>     }
> 
>     yield GlodaIndexer.kWorkDone;
>   },

https://dxr.mozilla.org/comm-central/rev/e3a88b8c91e2267ace82651ec29049f1f451aaca/mail/components/im/modules/index_im.js#642
>   _worker_logsFolderSweep: function(aJob) {
>     let dir = FileUtils.getFile("ProfD", ["logs"]);
>     if (!dir.exists() || !dir.isDirectory())
>       return;
> 
>     // Sweep the logs directory for log files, adding any new entries to the
>     // _knownFiles tree as we traverse.
>     let children = dir.directoryEntries;
>     while (children.hasMoreElements()) {
>       let proto = children.getNext().QueryInterface(Ci.nsIFile);
>       if (!proto.isDirectory())
>         continue;
>       let protoName = proto.leafName;
>       if (!Object.prototype.hasOwnProperty.call(this._knownFiles, protoName))
>         this._knownFiles[protoName] = {};
>       let protoObj = this._knownFiles[protoName];
>       let accounts = proto.directoryEntries;
>       while (accounts.hasMoreElements()) {
>         let account = accounts.getNext().QueryInterface(Ci.nsIFile);
>         if (!account.isDirectory())
>           continue;
>         let accountName = account.leafName;
>         if (!Object.prototype.hasOwnProperty.call(protoObj, accountName))
>           protoObj[accountName] = {};
>         let accountObj = protoObj[accountName];
>         let convs = account.directoryEntries;
>         while (convs.hasMoreElements()) {
>           let conv = convs.getNext().QueryInterface(Ci.nsIFile);
>           let convName = conv.leafName;
>           if (!conv.isDirectory() || convName == ".system")
>             continue;
>           if (!Object.prototype.hasOwnProperty.call(accountObj, convName))
>             accountObj[convName] = {};
>           let job = new IndexingJob("convFolderSweep", null);
>           job.folder = conv;
>           job.convObj = accountObj[convName];
>           GlodaIndexer.indexJob(job);
>         }
>       }
>     }
>   },
Flags: needinfo?(arai.unmht)
Reporter

Comment 14

3 years ago
(In reply to Tooru Fujisawa [:arai] from comment #13)
 It should be quicker to just trace what's passed to the `push` method as
> `aIterator` parameter.

> There, the following 2 functions are not ES6 generator.
> (latter is even not a generator...)

Thanks for the quick analysis. So you're saying that the `aIterator` sometimes gets called with generators and other times it doesn't?

In this case my patch is correct and we should just remove the:
  this.activeIterator.return(); ?

Or is there a way to test? Do you have a better solution than mine?
Flags: needinfo?(arai.unmht)
Assignee

Comment 15

3 years ago
Or rather that we should convert those 2 functions to generators. Maybe I forgot that in the bug 	1292569.
(In reply to :aceman from comment #15)
> Or rather that we should convert those 2 functions to generators.

yes.
Flags: needinfo?(arai.unmht)
Reporter

Comment 17

3 years ago
(In reply to :aceman from comment #15)
> Or rather that we should convert those 2 functions to generators. Maybe I
> forgot that in the bug 1292569.
So for _worker_logsFolderSweep: function(aJob) we just add the * and for _worker_logsFolderSweep: function(aJob) we add a * and a yield? Of what? Anyway, I think I'll leave it in your capable hands, feel free to obsolete my patch ;-)
Assignee

Comment 18

3 years ago
Asuth, may you know if we really need to add some "yield" to _worker_logsFolderSweep() ? Maybe it is fine if it just runs without returning any value. We just add the "*" so that the function class is correct.

Yes, it seems _worker_index_card() just needs a "*" to be added.
Component: Database → Search
Flags: needinfo?(bugmail)
OS: Unspecified → All
Hardware: Unspecified → All
Version: unspecified → Trunk
eslint tends to get mad if you use a "function*" without an actual yield, and I'm inclined to believe it's against the spec to do so.  I'm not sure SpiderMonkey actually gets mad.  It's probably easiest to just add a "yield GlodaIndexer.kWorkDone;" to the bottom of the function since then it's definitely a legal generator and then all the generators are also operating equivalently as far as the gloda driver is concerned.
Flags: needinfo?(bugmail)
Assignee

Comment 20

3 years ago
Thanks arai and asuth. Let's try if the changes help.
Component: Search → Database
Assignee

Comment 21

3 years ago
Jorg, please try running with this.
Attachment #8788627 - Flags: feedback?(jorgk)
Reporter

Comment 22

3 years ago
(In reply to :aceman from comment #21)
> Jorg, please try running with this.
Sadly it's not that easy. The problem only shows intermittently in production. Your patch looks right, so let's land this and I'll try it in a Daily, OK?
Reporter

Updated

3 years ago
Attachment #8781122 - Attachment is obsolete: true
Reporter

Updated

3 years ago
Attachment #8781269 - Attachment is obsolete: true
Reporter

Updated

3 years ago
Attachment #8788627 - Flags: feedback?(jorgk) → review?(bugmail)
Attachment #8788627 - Flags: review?(bugmail) → review+
Assignee

Comment 23

3 years ago
Yes, no problem with that.
Assignee: nobody → acelists
Status: NEW → ASSIGNED
Keywords: checkin-needed
Reporter

Comment 24

3 years ago
Let's land this after bug 1266836 comment #64 is merged to M-C.
Whiteboard: [landing: see comment #24]
Reporter

Comment 25

3 years ago
Ready to go now (https://hg.mozilla.org/mozilla-central/rev/a5029e21db24). No, there is no dependency, I just wanted to see whether some of the test failures from bug 1300059 are fixed now with that landed.
Whiteboard: [landing: see comment #24]

Comment 27

3 years ago
Thanks for fixing this! It's a shame there is no test that caught it.
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Keywords: checkin-needed
Resolution: --- → FIXED
Target Milestone: --- → Thunderbird 51.0
Reporter

Comment 28

3 years ago
(In reply to Jorg K (GMT+2, PTO during summer) from comment #22)
> (In reply to :aceman from comment #21)
> > Jorg, please try running with this.

> Sadly it's not that easy. The problem only shows intermittently in
> production. Your patch looks right, so let's land this and I'll try it in a
> Daily, OK?

Appears to work ;-) I haven't seen the problem reported here again. Thanks again.
Status: RESOLVED → VERIFIED

Updated

2 years ago
Depends on: 516523
You need to log in before you can comment on or make changes to this bug.