Meik Neubauer Reporter
	Description • 9 years ago

Thunderbird 38.3.0; no extensions (except Log Helper 0.6.1); no themes (except default); all multimedia-plugins disabled; Global search/index disabled; hw acceleration disabled; 0MB cache

System: Lubuntu 14.04LTS; 1GB RAM; 2,5GB cryptswap; is a Virtualbox VM;
thunderbird profile is on separate, dedicated VHD;
there is nothing else running on this system, except firefox (which is idle)

TB has no mail accounts; just used for RSS feeds; check for articles at startup disabled; about 150 (sub-)folders with feeds. Total size of profile folder: 235,5MB.

After Thunderbird started, memory consumption is about 500MB.
Manually "Get Messages -> News Feeds".
Thunderbird quickly consumes all RAM, then expands fully into the swapfile.
It becomes unresponsive - impossible to get an about:memory report.
It does not crash. It actually downloads the feeds from the internet and displays updates in the folder pane. However, it continues with heavy swapping for about 2 hours before it quickly settles back down to the normal 500MB memory claim.

I did some tracing of what I thought would be helpful:
About 300k lines of "InMemoryDataSource: ASSERT" followed by "InMemoryDataSource: MARK", both four times for (as it appears) each feed item.
After that a large list of "InMemoryDataSource: UNASSERT", but seemingly not for all feed items.
Intermittent nsObserverService::AddObserver(7f1b0ce1f3e0: memory-pressure).
Then a large section (hundreds of k lines) with "InMemoryDataSource: UNASSERT", followed TWICE by "InMemoryDataSource: ASSERT" for specific feed items.
Alternatively there is a sequence UNASSERT - ASSERT - UNASSERT -ASSERT for specific feed items.

Database open counts are normal during the whole process.
The complete log has 3,3 million lines, 400MB.

The problem is reproducible with each application start. After the initial problem phase, thunderbird does not show any anomalies.

	Wayne Mery (:wsmwk)
	Comment 1 • 9 years ago

> After Thunderbird started, memory consumption is about 500MB.

that in itself seems rather high.

what memory usage do you have if you start thunderbird with 
 -offline

	Meik Neubauer Reporter
	Comment 2 • 9 years ago

(In reply to Wayne Mery (:wsmwk, use Needinfo for questions) from comment #1)
> > After Thunderbird started, memory consumption is about 500MB.
> 
> that in itself seems rather high.

I was not precise enough:
500MB is for the whole system, including the running firefox.
Thunderbird itself consumes only 140MB (explicit allocation).

	Wayne Mery (:wsmwk)
	Comment 3 • 9 years ago

> Thunderbird itself consumes only 140MB (explicit allocation).
is that -offline ?
and then when you go online, what does memory go up to for thunderbird-only?

can you narrow down which feed might be causing the high memory?

	Meik Neubauer Reporter
	Comment 4 • 9 years ago

./thunderbird -offline    ==>   71MB
switch to online          ==>  100MB

both measurements from thunderbird's about:memory

I will try to attach the memory reports.

I cannot determine whether a specific feed is causing the problem. The feed configuration did not change for many weeks. I sometimes had similar problems before (also with older tb versions), but never so massive as it is now (e.g. experienced +250MB for 5 minutes or so, and never regularly).

	Meik Neubauer Reporter
	Comment 7 • 9 years ago

I just managed to get a memory report while the problem is showing.
I had about:memory open and fortunately a mouse click on the Measure button went through and the display updated:

Explicit allocations:
1,447.78 MB (100%) explicit
|--1,258.91 MB (86.95%) -- heap-unclassified
|-----63.73 MB (04.40%) -- heap-overhead  (o/w 31MB bookkeeping and 30MB bin-unused)
...rest looks reasonable


Won't be able to save this data in a file.

	Meik Neubauer Reporter
	Comment 8 • 9 years ago

(In reply to bugrider from comment #7)
> I just managed to get a memory report while the problem is showing.
> I had about:memory open and fortunately a mouse click on the Measure button
> went through and the display updated:
> 
> Explicit allocations:
> 1,447.78 MB (100%) explicit
> |--1,258.91 MB (86.95%) -- heap-unclassified
> |-----63.73 MB (04.40%) -- heap-overhead  (o/w 31MB bookkeeping and 30MB
> bin-unused)
> ...rest looks reasonable
> 
> 
> Won't be able to save this data in a file.

I tried to get another report later, when it consumed more memory, but it did not respond anymore.
I let it run over night. Next morning it was idle and showed an unresponsive script warning.
I chose continue and then it crashed. Sent crash report with the tool window that came up. I added my eMail address. Maybe it can be found somewhere...

	Wayne Mery (:wsmwk)
	Comment 9 • 9 years ago

alta88, I do not know of any bugs with feeds that might cause high memory usage, do you?

I wonder if this is not just a bad feed folder.

	alta88
	Comment 10 • 9 years ago

The op simply does not have enough resources to process all feeds at one time.  Once both ram and a swap file are full, it's all over and the OS will freeze and may not recover.

Once a particular feed file is processed to completion, its memory is explicitly nulled. Although most processing is async, there is the fundamental (minor) bottleneck of storing all new messages for a feed synchronously on the main thread to local mbox. However, the real problem is that the original design processes all feeds on the same interval (bug 257037) and didn't have any balancing logic.

Workarounds are:
1) Increase the swap.
2) Separate the single feed account into two or more with different update intervals.

	Wayne Mery (:wsmwk)
	Comment 11 • 9 years ago

glad I cced you, and that we know what needs to be worked on.

Would not an additional strategy be for user to disable checking of feeds on startup? (where we are already under some heavy load, which tends to make everything take longer)

Let's leave this open until bug 257037 is resolved so that it's clear to users, and that it impacts our startup performance

	Meik Neubauer Reporter
	Comment 12 • 9 years ago

(In reply to alta88 from comment #10)

I disagree with this analysis.

> The op simply does not have enough resources to process all feeds at one
> time.  

The user profile folder is 134MB (just now), the Feeds folder with all feeds is 89MB. Even considering bad programming techniques, a free RAM+Swap size of 3GB should be sufficient.

> Once both ram and a swap file are full, it's all over and the OS will
> freeze and may not recover.

The OS does not freeze - only becomes a bit sluggish. Thunderbird becomes unresponsive, but does not produce errors. After all, seems that Tb handles the memory strain well.

> Once a particular feed file is processed to completion, its memory is
> explicitly nulled. Although most processing is async, there is the
> fundamental (minor) bottleneck of storing all new messages for a feed
> synchronously on the main thread to local mbox. However, the real problem is
> that the original design processes all feeds on the same interval (bug
> 257037) and didn't have any balancing logic.

If that is the problem, why do I experience this only once after Tb has started - and NOT on any subsequent feed updates (auto-interval = 15 min.)?

	Meik Neubauer Reporter
	Comment 13 • 9 years ago

(In reply to Wayne Mery (:wsmwk, use Needinfo for questions) from comment #11)
> Would not an additional strategy be for user to disable checking of feeds on
> startup? (where we are already under some heavy load, which tends to make
> everything take longer)

Feed checking at startup IS DISABLED!
The problem does not show automatically after Tb startup is complete. It occurs only when the feeds are updated for the first time after startup. This can be triggered manually or by the interval timer (set to 15 mins.).

The problem does NOT SHOW on any later feed updates (manual or timed)!

	Wayne Mery (:wsmwk)
	Comment 14 • 9 years ago

another example https://groups.google.com/forum/#!search/%22Out$20of$20memory$20crash$20at$20getting$20messages%22/mozilla.support.thunderbird/vN749dYoB38/VK2PO36dBAAJ

	Meik Neubauer Reporter
	Comment 15 • 9 years ago

The problem is (as expected) still present in TB 38.4.0.

	Meik Neubauer Reporter
	Comment 16 • 8 years ago

The problem is still present in TB 45.6.0.

In the meantime I found a workaround procedure that can drastically reduce the time needed for the first get of RSS feeds after startup. This workaround procedure does NOT seem to reduce the excessive memory consumption.

Procedure:
1. Start TB
2. Edit->Account Settings->News Feeds: Disable "Check for new articles every xx minutes"
3. Close and restart TB (because a change in this setting is not reflected until TB is restarted (which might be another bug))
4. In the tree view of all feeds, select a small range of feed folders. Then right-click on the selection and "Get Messages". This will retrieve the feeds for only the selected folders.
5. Wait for disk and network activity for this small feed update to finish.
6. Repeat steps 4 and 5 until all feed folders have been updated.
7. File->Compact Folders
8. Edit->Account Settings->News Feeds: Re-Enable "Check for new articles every xx minutes"
9. Close and restart TB
10. In the Mail Toolbar: Get Messages->News Feeds

After step 10 the same excessive memory consumption is experienced.
However, the time interval until TB reaches a normal state again is drastically reduced.
In my case the reduction was from 8 hours to less than 1 hour.

Hope this helps in debugging.

	Meik Neubauer Reporter
	Comment 17 • 7 years ago

I found an additional trick to reduce BOTH the excessive memory consumption AND the time needed for the first get of RSS feeds after starting TB:

Altering the procedure as laid out in my 2017-01-03 comment as follows (with numbering referring to that post):
9a. Disconnect from the network (e.g. by unplugging the network cable)
10. [unchanged from 2017-01-03 post] In the Mail Toolbar: Get Messages->News Feeds
    This will rather quickly come to an end, because due to the missing network connection no feeds are found.
11. Reconnect to the network.
12. Repeat step 10, i.e.: In the Mail Toolbar: Get Messages->News Feeds

With this little trick, the time interval until TB reaches a normal state again could further be reduced from somewhat less than an hour to about 6 minutes. ALSO, it seemed to me that the excessive memory consumption is reduced too, although there was still some swapping, which does not occur with subsequent feed updates (i.e. any update after the first get, manually or by automated time interval). [BTW: These subsequent feed updates take less than 1 minute to update all RSS feeds.]

So to sum everything up (for my specific case):
a) Just starting TB and get all news feeds: Runtime 8 hours, swapping up to 1.8GB (on 2GB swap partition).
b) Using procedure from 2017-01-03 post: Runtime ca. 1 hour, swapping up to 1.8GB
c) Additionally unplugging network on first get: Runtime 6 minutes, swapping up to 700MB (ca.)
d) any subsequent get of feeds: Runtime: <1 minute, no swapping.

	alta88
	Comment 18 • 7 years ago

bug 1312813 has landed.