1057516 - Thunderbird becomes unresponsive, shows huge read lseek I/O operations to small imap Trash folder and high CPU. filters deletes roughly 2000 emails/day. (Bad Trash folder?)

Status: RESOLVED INCOMPLETE

(MailNews Core :: Filters, defect)

Description

[LvH]

User Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/36.0.1985.143 Safari/537.36

Steps to reproduce:

- Note: Also present in version 31 -
- Note2: conversation had with :wsmwk and :irving on IRC -

It's hard to know "what I did" other than using Thunderbird, so I'll say a bit more about my configuration:
- Intel Core i5-2467M, 8GB DDR3 Memory, Samsung 840 EVO SSD
- Thunderbird 24.7.0 (Note: also tested 31)
- Fedora 20 x86_64
- No e-mail synchronization, all disabled
- Tested both with "compact" turned on and off, no difference
- Roughly 10 e-mail accounts in there, large ones (thousands of e-mails)


Actual results:

Thunderbird at random times suddenly becomes extremely slow and unresponsive, near impossible to use. It can take days for that to go away, then it remains being stable for a long time. Last time I encountered this problem was roughly 1.5 months ago.

A strace indicates Thunderbird is doing something with a Trash.msf file.
(.thunderbird/ad8upbcn.default/ImapMail/thor.****.*****/INBOX.sbd/Trash.msf)

Strace output:
read(46, "0 {(k^98:c)(s=9)4AA4:m } 46FFF4 "..., 8192) = 8192
lseek(46, 12591104, SEEK_SET)           = 12591104
read(46, ":c)(s=9)4B5E:m } 4700AE }\n{4700A"..., 8192) = 8192
lseek(46, 12599296, SEEK_SET)           = 12599296
read(46, "4C18:m } 470168 }\n{470169:^80 {("..., 8192) = 8192
lseek(46, 12607488, SEEK_SET)           = 12607488
read(46, " 470222 }\n{470223:^80 {(k^98:c)("..., 8192) = 8192
lseek(46, 12615680, SEEK_SET)           = 12615680
(Note: sometimes you can see e-mail subjects in the output)

That output is repeated in similar ways thousands and thousands of times.
Leaving it running for approximately 10 to 15 minutes resulted in a strace output of 355MB.

The trash file is merely 18MB in size.
The hard drive was, during a short test (write 512MB file), capable of writing with 380MB/sec. (Samsung 840 EVO SSD)


In version 31.0, the same problem occurs (on its own, I didn't even open an e-mail, I didn't even try to open a mailbox. I just left Thunderbird to sit there after starting up, after roughly a minute or so it started.), however the strace output is slightly different:

read(62, "F)(^C8=0)(^C5=8)(^C9^509E)(^CA=1"..., 8192) = 8192
_llseek(62, 16220160, [16220160], SEEK_SET) = 0
read(62, "[4707BD(^C6^1C1E6)(^C8=0)(^C5=8)"..., 8192) = 8192
_llseek(62, 16228352, [16228352], SEEK_SET) = 0
read(62, ")(^CA=10118)]\n  [47084D(^C6^1C49"..., 8192) = 8192
_llseek(62, 16236544, [16236544], SEEK_SET) = 0
read(62, "(^C5=8)(^C9^509E)(^CA=10085)]\n  "..., 8192) = 8192
_llseek(62, 16244736, [16244736], SEEK_SET) = 0
read(62, "C8=0)(^C5=8)(^C9^509E)(^CA=fff4)"..., 8192) = 8192
_llseek(62, 16252928, [16252928], SEEK_SET) = 0

Thunderbird reports it uses roughly 80 to 95% CPU, in bad situation it claims 115 ~ 130 sometimes, and about 12% of the memory in use. (4GB, so it uses less than 512MB)

As soon as the problem starts, ThunderBird becomes unusable. Blank screens which takes very long to dissolve back in to something displaying, trying to open Preferences took well over 2 minutes, reading e-mail is pretty much impossible unless you're lucky, and sending e-mail simply results in time-outs as the server disconnects before Thunderbird actually sends anything. 

I do not know how to properly reproduce this problem as I don't know *WHAT* causes it. 

For good measure, here is the "problematic" account files plus sizes:
[lvhultrabook thor.*****.*****]$ du -h --max-depth=1
19M	./INBOX.sbd
42M	.
[lvhultrabook thor.*****.*****]$ ls -lh
total 24M
-rw-rw-r--. 1 user user 1.2K Jan 25  2014 Archives.msf
-rw-rw-r--. 1 user user 1.2K Jan 25  2014 Drafts.msf
-rw-------. 1 user user   80 Jan 25  2014 filterlog.html
-rw-rw-r--. 1 user user  23M Aug 22 21:03 INBOX.msf
drwx------. 4 user user 4.0K Aug 20 21:59 INBOX.sbd
-rw-r--r--. 1 user user  196 Jan 25  2014 msgFilterRules.dat
-rw-rw-r--. 1 user user 1.2K Jan 25  2014 Sent.msf
-rw-rw-r--. 1 user user 1.2K Jan 25  2014 Templates.msf
[lvhultrabook thor.*****.*****]$ cd INBOX.sbd/
[lvhultrabook thor.*****.*****]$ du -h --max-depth=1
4.0K	./Trash.sbd
12K	./Archives.sbd
19M	.
[lvhultrabook thor.*****.*****]$ ls -lh
total 19M
-rw-rw-r--. 1 user user 1.4K Jan 25  2014 Archives.msf
drwx------. 2 user user 4.0K Jan 25  2014 Archives.sbd
-rw-rw-r--. 1 user user 4.7K Aug  6 02:17 Drafts.msf
-rw-rw-r--. 1 user user 276K Aug 20 21:28 Junk.msf
-rw-rw-r--. 1 user user 1.3K Jan 25  2014 Queue.msf
-rw-rw-r--. 1 user user 521K Aug 10 04:14 Sent.msf
-rw-rw-r--. 1 user user 1.3K Jan 25  2014 Templates.msf
-rw-rw-r--. 1 user user  18M Aug 22 17:54 Trash.msf <<< File being the problem for Thunderbird, according to lsof + strace output.
drwx------. 2 user user 4.0K Feb 18  2014 Trash.sbd
-rw-rw-r--. 1 user user 1.3K Jan 25  2014 Versturen.msf


Expected results:

It shouldn't hang. :)

Comment 1

[LvH]

Forgot to mention, this is all IMAP.

Comment 2

[Wayne Mery (:wsmwk)]

This sounds like an absurd test, but what happens if you set thunderbird offline - file | offline | work offline ?

Comment 3

[Magnus Melin [:mkmelin]]

Gloda indexing perhaps? You can try to turn it off under Preferences | Advanced | General | Enable Global Search and Indexer

Comment 4

[LvH]

Hi guys,

Search index was already disabled.

As for offline mode: I'm sorry, but I can't test it.
The problem is so bad that I can't even get it set to offline mode... Lately its just been hanging on a blank screen while this problem is going; becomes totally unresponsive. :/

I guess it doesnt accept commands from console to put it in to offline mode?
Although perhaps it would work if I just like... Pull my internet cable; will that have the same effect you want to try and achieve, or must it really go in to Offline mode in Thunderbird itself?

Comment 5

[Wayne Mery (:wsmwk)]

In that case *start* thunderbird with  -offline   switch.  :)
Please see https://developer.mozilla.org/en-US/docs/Mozilla/Command_Line_Options#Linux

Comment 6

[LvH]

Hi,

Did that.
Problem didn't seem to occur (with the lots of read/write) when being in offline mode, although it did still seem a bit laggy. Switching to online mode didnt always instantly cause trouble, usually after a while though.
Perhaps should mention I also have filters setup, I guess it deletes roughly ~2000 emails/day. Which should barely be an issue.

I'm afraid I had to nuke this test case now.
I did make more strace outputs should you need them, but the last 4 days: ThunderBird would only present a blank screen and nothing more, other than causing huge CPU loads (whilst, strangely enough, sometimes strace didn't output anything at all whilst cpu load was 100% or so.). I left it running 2 days in a row to see if it would clear up an issue perhaps, unfortunately not.
I needed my mail client operational again, so I killed the account responsible for the problem and added it back again.

... Which seems to have worked reasonably. It had to download all headers again and the amount of e-mail it had to download made it laggy as well: but at least it functions again, and I can read my mail.
Sorry, wish I could have helped more here; but I couldn't waste any more time without e-mail.

I'm sure the problem will pop back up in a few weeks though. It always does.
Perhaps by then we can figure out what the next step in testing is; there is no reasonable cause, in my opinion, why it should completely become unusable due to mere IMAP headers. (There is a lot of them, but it takes only a few MB... It shouldn't cause it to hang up for hours in a row.)

Comment 7

[Wayne Mery (:wsmwk)]

Thanks. If you see the problem again, please do reopen the bug report

Comment 8

[Wayne Mery (:wsmwk)]

changing resolution from WFM to incomplete, because the testcase is gone, but thanks to LvH we have some good information in the bug.

lots of linux examples in https://bugzilla.mozilla.org/buglist.cgi?keywords=perf&f1=short_desc&keywords_type=allwords&o3=anywordssubstr&list_id=12618673&o1=nowordssubstr&classification=Client%20Software&classification=Components&query_format=advanced&f3=short_desc&f2=OP&longdesc=lseek%20read&product=MailNews%20Core&product=Thunderbird&longdesc_type=allwordssubstr

Comment 9

[ISHIKAWA, Chiaki]

Hi, I have finally managed to salvage my hardware and more importantly my disk files and have been able to compile TB locally, update the TB source tree and compile, and now testing comm central compile submission. If everything works out, I will begin checking pending isuees (patches including the looping Mac issue which was caused by the backed-out patch and this problem maybe on the side).
Thank you for the patience.

Comment 10

[Wayne Mery (:wsmwk)]

(In reply to LvH from comment #6)
> ... 
> I'm sure the problem will pop back up in a few weeks though. It always does.

LvH, if your problem continues, please reopen the bug report

Comment 11

[ISHIKAWA, Chiaki]

read/lseek strace output suggests that at the time of data collection,
TB seems to have read the trash folder file (folder is actually a mbox file by default) 
sequentially with 8KB buffering. So it looks that is either doing compaction or gloda.
(In the case of compaction, it will output eventually). 
That there is no strace output sometimes suggests a looping javascript code snippet or something. Just my wild-guess at this moment.

Comment 12

[Wayne Mery (:wsmwk)]

Default setting is Gloda doesn't index trash. So it "shouldn't" be a factor.