843639 - gloda implications of indexing / downloading email with hundreds of email addresses, memory usage rises to ~300MB/sec until it crashes

Status: REOPENED

(Thunderbird :: Search, defect)

Description

[danieleds0]

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:19.0) Gecko/20100101 Firefox/19.0
Build ID: 20130218103006

Steps to reproduce:

When I open Thunderbird (17.0.2), it crashes after a few seconds. The whole system is slowed down.
It used to work correctly... I don't know what happened. No system updates. My OS is Ubuntu 12.10 64bit.


Actual results:

I noticed that the RAM usage of Thunderbird rises to something like 300MB/sec and never stops. So, after a few seconds, the whole system becomes unresponsive.
This only happens when thunderbird downloads emails. If I start thunderbird in offline mode, it works correctly.
I tried to start thunderbird in safe mode, but nothing changed.

Comment 1

[:aceman]

Is that a POP3 server? Are your received messages big?

Comment 2

[danieleds0]

There are POP3 and IMAP servers. My messages are not big, I checked with the web client.

I did a new test: I disabled my system network connection, and then I started thunderbird. It still results in a never-stopping memory usage.
Like I said, instead, if I run thunderbird in offline mode (the offline mode *within* thunderbird) the problem doesn't occur.

Comment 3

[:aceman]

Can you manage to view tools->error console and tools->activity manager before TB crashes? Are there any messages there?

Comment 4

[danieleds0]

Attachment: Messages

Comment 5

[danieleds0]

Attachment: Messages (part 2)

Comment 6

[danieleds0]

Attachment: Activity manager

Comment 7

[danieleds0]

Comment on attachment 717109 [details]
Messages

TB started in safe mode

Comment 8

[:aceman]

Ok, and can we assume those errors are numerous and increasing rapidly as TB runs? That may be the source of the memory consumption.

Have you changed the folder view in View -> folders -> something?
Can you switch to the "All" view?

Comment 9

[danieleds0]

Hmm yes, those errors are numerous, but they're not increasing.
If I'm quick enough to clear them, no new error shows up.

I tried switching to the "All" view too, but nothing changed.

Could it be related to the "indexing" activity shown in the last screenshot?

Comment 10

[:aceman]

The indexing should finish after messages are downloaded.
Also, you can disable the indexing to rule it out as the source of the problems. It is in Options -> Advanced -> enable global search and indexer .

Comment 11

[danieleds0]

Great! :)
Looks like the problem is actually the 'global search and indexer' feature.
I disabled it, then thunderbird crashed, but the next times it was stable on ~180MB of memory (with 1.2 GB of virtual memory).

If I re-enable it while thunderbird is running, no problem occurs. The problem only happens when thunderbird *starts* with indexing enabled.
I'd like to manually launch the indexing to see if it's really like I said, but I have no idea how to do it.

Comment 12

[Wayne Mery (:wsmwk)]

(In reply to danieleds0 from comment #11)
> Great! :)
> Looks like the problem is actually the 'global search and indexer' feature.
> I disabled it, then thunderbird crashed, 

did it produce a crash report?

> but the next times it was stable on
> ~180MB of memory (with 1.2 GB of virtual memory).
> 
> If I re-enable it while thunderbird is running, no problem occurs. 

indexing can't be effectively enabled with Thunderbird running. It *requires* a restart.  (disable behaves differently - it takes effect immediately)

Comment 13

[danieleds0]

(In reply to Wayne Mery (:wsmwk) from comment #12)
> did it produce a crash report?

Nope. I've not been very clear about the "crash", this is what happens:
 - Thunderbird starts eating memory
 - Thunderbird becomes unresponsive, the memory usage keeps rising
 - The whole system is slowed down by the swapping process, memory keeps rising
 - I have to kill thunderbird

If I don't kill it in time... well... the pc is not usable anymore and I have to do an "hard reset".

Comment 14

[:aceman]

For your information, when you set TB into the offline mode, the indexer is suspended even if it would have any work to do (unindexed messages). That may explain why it was fine in offline mode even with indexer enabled.

Comment 15

[danieleds0]

The same problem occurs on another Ubuntu 12.10 setup.

Comment 16

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

Possibilities:
- Streaming message bodies is leaking memory for some reason.  An extension or plugin?  I realize safe mode was used, so this probably shouldn't be happening.  Also, for something like enigmail which does get involved in streaming, I don't think we'd see it.

- Gloda is running way too fast.  Maybe a regression in the timing code that tells us how much work we are doing?  This would be a little surprising since we moved that code into TB from platform, so there should be no platform surprises.  If gloda is going super fast, it's possible that the GC heuristics keep increasing our heap usage.

- An extension is using the test-only gloda query that captures all newly index gloda messages, so gloda effectively acts like a memory leak since no indexed messages are forgotten.

- Some type of SQLite problem related to caching and a failure on our part to commit a transaction.

The attachments aren't shedding any light for me.  Turning on gloda debug would provide some info about how much indexing gloda is doing and whether there are any errors happening:
https://wiki.mozilla.org/Thunderbird:Debugging_Gloda

Comment 17

[danieleds0]

Thanks Andrew, I may have found the problem.
I turned on gloda debug, and I obtained *a lot* of lines like the following:

2013-02-27 21:30:57   gloda.NS   DEBUG   creating contact for 'null' ([e-mail])

We're talking about something like ~3000 lines before the system starts swapping everything out.
Every address is different for every line.

I searched one of these addresses from within Thunderbird and indeed I found a mass-mail containing more than 3100 addresses in carbon copy. Awesome...
http://s9.postimage.org/afrrvf4vz/tbmail.png

My screenshot is not in English, however if I click on the "more 3126" link, then Thunderbird freezes (but in this case, memory usage doesn't increase). After some seconds the full list of addresses shows up, but if I try scrolling it, thunderbird freezes again (and after some time asks if you want to stop the script "chrome://global/content/bindings/text.xml:39"). Whatever the answer, it then starts behaving normally.

(the giant memory leak at the start, of course, is still present)

I'll wait before deleting the problematic email, in case you need some other information.

Comment 18

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

Hm, I thought we had a test case that covered this, but it's only a test of the query engine in test_lots_of_string_constraints because the query engine is what broke, not gloda.

I understand why the message reader UI chokes when you expand (it's a lot of DOM nodes, and it's conceivable there's some type of bad growth rate or general inefficiency.)

Gloda's approach to finding address book cards is fairly sane and has been the same for a loooong time.  Maybe there was a change in the address book and we end up instantiating duplicate copies of the address book each time we go looking for address book cards?  

https://mxr.mozilla.org/comm-central/source/mailnews/db/gloda/modules/utils.js#91

mconley/standard8 should know if there were any changes that could impact memory use/retention.


Otherwise, the best best is to try the gecko profiler for Thunderbird and see if there are any obvious smoking guns that show up there.  Trying on a nightly build of thunderbird may be required and/or at least produce significantly better stack traces.

Comment 19

[Mike Conley (:mconley) (:⚙️)]

(In reply to Andrew Sutherland (:asuth) from comment #18)
> Hm, I thought we had a test case that covered this, but it's only a test of
> the query engine in test_lots_of_string_constraints because the query engine
> is what broke, not gloda.
> 
> I understand why the message reader UI chokes when you expand (it's a lot of
> DOM nodes, and it's conceivable there's some type of bad growth rate or
> general inefficiency.)
> 
> Gloda's approach to finding address book cards is fairly sane and has been
> the same for a loooong time.  Maybe there was a change in the address book
> and we end up instantiating duplicate copies of the address book each time
> we go looking for address book cards?  
> 
> https://mxr.mozilla.org/comm-central/source/mailnews/db/gloda/modules/utils.
> js#91
> 
> mconley/standard8 should know if there were any changes that could impact
> memory use/retention.
> 

Nothing really radical has happened in the address book code for some time... Daniel, are you using any contact-releated add-ons? The EDS Integration add-on, for example?

> 
> Otherwise, the best best is to try the gecko profiler for Thunderbird and
> see if there are any obvious smoking guns that show up there.  Trying on a
> nightly build of thunderbird may be required and/or at least produce
> significantly better stack traces.

This *would* be an excellent way of getting our data, but unfortunately, we're not getting any symbols from the symbol server, rendering the profiles somewhat useless for now. :/ See bug 843367.

Comment 20

[danieleds0]

Hmm yes, I'm actually using the EDS Integration add-on, but I tried safe-mode with every add-on disabled and the problem doesn't disappear.

Comment 21

[Mike Conley (:mconley) (:⚙️)]

(In reply to danieleds0 from comment #20)
> Hmm yes, I'm actually using the EDS Integration add-on, but I tried
> safe-mode with every add-on disabled and the problem doesn't disappear.

Hm, OK. Maybe take this opportunity to double-check, because I could believe that the EDS Integration add-on is bogging you down.

Once we get TB symbols in the symbol server, a profile would (hopefully) help narrow this down.

Comment 22

[danieleds0]

Ok, I just triple-checked: same problem with a normal thunderbird start, same problem with safe-mode, same problem with a normal start with EDS Integration disabled.

Comment 23

[Wayne Mery (:wsmwk)]

danieleds

Profiler should be working now. Can you try it with beta from http://www.mozilla.org/thunderbird/channel/ ?

Comment 24

[danieleds0]

With the current beta, Thunderbird doesn't crash anymore even with the indexer enabled. I don't really know what the "indexer" does, but could it be that the message is already indexed? If so, I think I should try to un-index it. (how?)

Anyway, this is the output of the profiler when clicking on the "more 3126" link:
http://people.mozilla.com/~bgirard/cleopatra/?1375001223140#report=2471f3049abef77c5f1357a2bc6c649e1e932c09

Comment 25

[Wayne Mery (:wsmwk)]

To unindex, simply delete global-messages-db.sqlite

Comment 26

[danieleds0]

No crash even after deleting global-messages-db.sqlite

Comment 27

[danieleds0]

Just kidding, it started showing up in the beta version too.
How can I use the gecko profiler if thunderbird freezes until I kill it?

Comment 28

[Wayne Mery (:wsmwk)]

iF thunderbird is "froze" there's no way to break in to start the profiler.

Comment 29

[danieleds0]

Deeply sorry for all these messages.
I took a closer look and this is the situation in the current beta:
 * with indexer enabled, the TB UI still freezes, but the memory leak is gone
 * without the memory leak and the resulting swapping, the system remains usable and TB returns active within a few minutes

So I was able to profile the process: http://people.mozilla.com/~bgirard/cleopatra/?1375016200995#report=3a5869ee4e8e6840885716dbde2b81eeeb22b262

Comment 30

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

the profile seems to show:
- a lot of time spent in creating identities for e-mail addresses during indexing in a way that dominated the event loop.  This suggests there's an e-mail with a ton of e-mail addresses in the to/cc lines or the system experienced bad swapping or something else that starved Thunderbird of CPU resources.
- following that, a long-running garbage collection triggered by gloda

Comment 31

[Wayne Mery (:wsmwk)]

(In reply to Andrew Sutherland (:asuth) from comment #30)
> the profile seems to show:
> - a lot of time spent in creating identities for e-mail addresses during
> indexing in a way that dominated the event loop.  This suggests there's an
> e-mail with a ton of e-mail addresses in the to/cc lines or the system
> experienced bad swapping or something else that starved Thunderbird of CPU
> resources.

correlates to bug 813496

Comment 32

[Wayne Mery (:wsmwk)]

morphing this to just cover gloda, which I'm guessing is less severe than other aspects related to bug 693295