485573 - Fennec runs out of memory and crashes if too many history items to sync

Status: RESOLVED FIXED

(Firefox :: Sync, defect, P1)

Description

[Jono Xia]

I thought we were processing history items sequentially, not all at once, so I don't see why the memory cost would keep increasing with the number of items -- unless we have a memory leak (rare in JS but not impossible) in the history engine.

Comment 1

[Jono Xia]

Attachment: Verbose log of crash

Comment 2

[Jono Xia]

The attatched log came from Madhava's N810.  I think, though I'm not sure, that the crash contained in the log was an instance of this bug.

Comment 3

[-fullmetaljacket-]

firefox also uses too much memory when weave is syncing, 150MB with just www.google.com opened on a single tab. do i need to file separate bug for that?

Comment 4

[Dan Mills [:thunder]]

It's almost certainly the same problem as this bug.

Comment 5

[Ed Lee :Mardak]

I wonder if this has anything to do with the base Engine class creating a new _storeObj() when accessing engine.store but HistoryTracker has its own _store that also creates a new HistoryStore().

Comment 6

[Dan Mills [:thunder]]

(In reply to comment #5)
> I wonder if this has anything to do with the base Engine class creating a new
> _storeObj() when accessing engine.store but HistoryTracker has its own _store
> that also creates a new HistoryStore().

That creates two stores, which is bad, but it's not actually a leak, right?

Comment 7

[Ed Lee :Mardak]

Doing some initial tests of incremental parsing...

Current logs doing full GET and big JSON.parse, etc..

2009-07-21 00:16:54     Engine.Bookmarks     INFO       521 outgoing items pre-reconciliation
2009-07-21 00:16:54     Engine.Bookmarks     DEBUG      Downloading & applying server changes
2009-07-21 00:16:55     Collection           DEBUG      GET request for https://sj-weave01.services.mozilla.com/0.3/user/EdTest2/bookmarks/?full=1&sort=depthindex
2009-07-21 00:16:59     Collection           DEBUG      GET request successful (200)
2009-07-21 00:17:00     BmkTracker           DEBUG      Removing changed ID {a89996e9-78ad-834c-8ef9-688f96f3cdcb}0
2009-07-21 00:17:09     BmkTracker           DEBUG      Removing changed ID {1a47c277-66a5-fa44-be01-97768588fef8}3
2009-07-21 00:17:09     Engine.Bookmarks     INFO       Applied 0 records, reconciled 521 records

Starts downloading at :55 and finishes ~4.5MB in 4 seconds. JSON.parse, and process records for 10 seconds. Total time of ~15 seconds.

New incremental parsing:

2009-07-21 00:14:39     Engine.Bookmarks     INFO       521 outgoing items pre-reconciliation
2009-07-21 00:14:39     Engine.Bookmarks     DEBUG      Downloading & applying server changes
2009-07-21 00:14:39     Collection           DEBUG      GET request for https://sj-weave01.services.mozilla.com/0.3/user/EdTest2/bookmarks/?full=1&sort=depthindex
2009-07-21 00:14:39     BmkTracker           DEBUG      Removing changed ID {a89996e9-78ad-834c-8ef9-688f96f3cdcb}0
2009-07-21 00:14:51     BmkTracker           DEBUG      Removing changed ID {1a47c277-66a5-fa44-be01-97768588fef8}3
2009-07-21 00:14:51     Collection           DEBUG      GET request successful (200)
2009-07-21 00:14:51     Engine.Bookmarks     INFO       Applied 0 records, reconciled 521 records

Starts downloading at :39 and starts processing immediately. Total time of ~12 seconds.

So slightly faster.. probably some from not needing to JSON.parse([..]) then record.deserialize(JSON.stringify). I just record.deserialize(json) directly.

No clue about memory usage though.. I'll try it on the n810 in the morning.

Comment 8

[Ed Lee :Mardak]

Attachment: v1

I'll convert my js shell tests for the incremental parser into actual weave tests in the morning..

I don't quite like the check for [,] but originally I just had it unconditionally strip off the first character because it should always start with { unless we just parsed a record, and then it would be either , or ].

But then I realized we might incrementally parse and end up on a not-done-record, so when we reenter on the next onDataAvailable, we've already stripped the comma. Maybe I should just insert a [...

Comment 9

[Ed Lee :Mardak]

Comment on attachment 389639 [details] [diff] [review]
v1

Doh. :p :dm] doesn't work anymore! it's :thunder ;)

Comment 10

[Dan Mills [:thunder]]

Comment on attachment 389639 [details] [diff] [review]
v1

Looks good, r=thunder.  Record parsing is fun!

Comment 11

[Ed Lee :Mardak]

Attachment: v1.1

So...... after much debugging and memory tracking and stuff...

Fennec was still crashing on n810 because of out of memory issues. Sometimes nsIMemory.isLowMemory() doesn't catch it early enough and we just crash. And when it does catch it, we're already too late and GC doesn't help. (?)

Also, we aren't leaking records or resources after doing a sync by checking with Atul's memory tracking code. So we must have been exploding in memory temporarily that Fennec couldn't handle.

So I made a tweak to run the GC, outside of the loop scope, after parsing a batch of records. And I'm able to sync my original test profile with ~4.5MB in ~500 fat bookmarks as well as a new test profile with ~6MB across 500 fat bookmarks and 400 thin ones.

Comment 12

[Ed Lee :Mardak]

Attachment: v1.1

Comment 13

[Ed Lee :Mardak]

Oh, and compared to current code, those two test profiles crash before they can even start processing any records.

Comment 14

[Ed Lee :Mardak]

http://hg.mozilla.org/labs/weave/rev/c475d2f9982e
Incrementally process records as the collection finds record boundaries and converts them to records for the engine to use. Get rid of the collection iterator and original RecordParser. Add tests for incremental record parsing and remove old iter tests.