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

Status: VERIFIED FIXED

(MailNews Core :: Database, defect)

Description

[Jorg K (CEST = GMT+2)]

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.

Comment 1

[Jorg K (CEST = GMT+2)]

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.

Comment 2

[Jorg K (CEST = GMT+2)]

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

Comment 3

[:aceman]

Can this.activeIterator just be null in this case? OR maybe some other object than expected. Can you dump it before the .return() call?

Comment 4

[Jorg K (CEST = GMT+2)]

Attachment: How about this?

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

Comment 5

[Jorg K (CEST = GMT+2)]

(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 ;-)

Comment 6

[:aceman]

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 7

[Andrew Sutherland [:asuth] (he/him)]

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

Comment 8

[Jorg K (CEST = GMT+2)]

Attachment: Debug patch - no good.

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.

Comment 9

[Jorg K (CEST = GMT+2)]

Aceman, can you give me a hand here or shall I just land the patch?

Comment 10

[:aceman]

You can also try:
1. this.activeIterator.toSource()
2. Object.keys(this.activeIterator)

Comment 11

[Jorg K (CEST = GMT+2)]

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?

Comment 12

[:aceman]

I'm still trying option 1 for now :)

Arai, do you have any new idea how to debug a generator?

Comment 13

[Tooru Fujisawa [:arai]]

(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);
>         }
>       }
>     }
>   },

Comment 14

[Jorg K (CEST = GMT+2)]

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

Comment 15

[:aceman]

Or rather that we should convert those 2 functions to generators. Maybe I forgot that in the bug 	1292569.

Comment 16

[Tooru Fujisawa [:arai]]

(In reply to :aceman from comment #15)
> Or rather that we should convert those 2 functions to generators.

yes.

Comment 17

[Jorg K (CEST = GMT+2)]

(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 ;-)

Comment 18

[:aceman]

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.

Comment 19

[Andrew Sutherland [:asuth] (he/him)]

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.

Comment 20

[:aceman]

Thanks arai and asuth. Let's try if the changes help.

Comment 21

[:aceman]

Attachment: convert remaining generators in gloda

Jorg, please try running with this.

Comment 22

[Jorg K (CEST = GMT+2)]

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

Comment 23

[:aceman]

Yes, no problem with that.

Comment 24

[Jorg K (CEST = GMT+2)]

Let's land this after bug 1266836 comment #64 is merged to M-C.

Comment 25

[Jorg K (CEST = GMT+2)]

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.

Comment 26

[aleth [:aleth]]

https://hg.mozilla.org/comm-central/rev/37f7bb383f98baadaf6d3e8ccf36608f46e0dc90
Bug 1294960 - convert missed generators in gloda indexer. r=asuth

Comment 27

[aleth [:aleth]]

Thanks for fixing this! It's a shame there is no test that caught it.

Comment 28

[Jorg K (CEST = GMT+2)]

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