472922 - Significant alloc/free of storage, possibly during sync

Status: RESOLVED FIXED

(Cloud Services :: General, defect)

Description

[Ray Mullins]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US; rv:1.9.0.5) Gecko/2008120122 Firefox/3.0.5
Build Identifier: 0.2.93

At various times, Firefox hangs and will not refresh windows.  Task Manager shows firefox.exe under 10% CPU, however the working set and commit sizes increase exponentially, double digit megabytes per refresh cycle, then suddenly plummet to where it was before the hang occurred.  I have seen the commit size approach 1.5GB!  Firefox will hang from anywhere from 5 to 15 minutes.  The performance graph will show a gradual rise, a plummet, then a gradual rise again.  It may do this three times or 30 times; it does not seem to be a tied to the number of windows or tabs open.

If I disable Weave, the behavior disappears, so it is definitely tied to it; whether or not it is in conflict with another extension, I have not confirmed.

Around the time of the hang, the brief log shows

2009-01-08 14:57:22	Service.Main	INFO	Running scheduled sync
2009-01-08 14:57:22	Service.Main	WARN	Could not get encryption passphrase

(I seem to get that encryption passphrase warning all the time, but it does not seem to affect it.)

The verbose log has almost 18K lines of BmkTracker trace and debug messages for about 2 minutes of activity, then this

2009-01-09 15:01:08	Service.Main	INFO	Running scheduled sync
2009-01-09 15:01:08	PubKeyManager	TRACE	Importing key: https://services.mozilla.com/0.3/user/zarchasmpgmr/keys/pubkey
2009-01-09 15:01:08	Record.PubKey	DEBUG	GET request for https://services.mozilla.com/0.3/user/zarchasmpgmr/keys/pubkey
2009-01-09 15:01:08	Record.PubKey	DEBUG	GET request failed (401)
2009-01-09 15:01:08	Record.PubKey	DEBUG	Error response: 
"Authentication failed"
2009-01-09 15:01:08	PubKeyManager	DEBUG	Failed to import key: Could not GET resource https://services.mozilla.com/0.3/user/zarchasmpgmr/keys/pubkey (401)
2009-01-09 15:01:08	Service.Main	WARN	Could not get encryption passphrase
2009-01-09 15:01:08	FaultTolerance	DEBUG	
Original exception: aborting sync, remote setup failed
Async stack trace:
module:wrap.js:161 :: WeaveCatchAllWrapper
module:wrap.js:93 :: WeaveNotifyWrapper
module:service.js:272 :: WeaveSvc__onSchedule
module:util.js:435 :: innerBind
module:util.js:475 :: EL_notify
Last callback created at module:wrap.js:130 :: WeaveLocalLockWrapper
2009-01-09 15:03:28	Chrome.Window	INFO	Sync window closed

Then another set of trace and debug messages, but this time for HistoryTracker.

I will admit that my bookmarks runneth amok; I have about 15K, a lot of duplicates.  I do know that I need to clean them up; I've been meaning to export and write a Perl script to clean them up.  If this behavior can be traced to the huge number of bookmarks, that will push this task higher on the list.

Reproducible: Sometimes

Steps to Reproduce:
It just happens, without warning; there is nothing obvious that I do to trigger this behavior.

Comment 1

[Dan Mills [:thunder]]

There have been significant memory management improvements singe 0.2.93.  Please re-test with a more recent build.

Comment 2

[Ray Mullins]

I just installed 0.2.98 (I thought I originally had that on this machine), but the exact same behavior is occurring.

I have also trimmed down my bookmarks, but as a part of that process I do have a lot of empty folders which I will now work on trimming as well.

Please let me know what diagnostics I can collect for you.

Comment 3

[Dan Mills [:thunder]]

Reopening, then.

Could you back up your bookmarks, then test with varying sizes of your bookmarks db? (just delete, say, half, then re-test).  I have tested with upwards of ~1500 bookmarks with few problems on OS X and Vista, so I'm trying to understand if this problem is due to the number of bookmarks or platform, or something else entirely.

Comment 4

[Ray Mullins]

As it turned out, the note in comment 2 about the trimmed bookmarks was not accurate, as somehow my purging of duplicates got messed up and the number of bookmarks actually increased.  I've made sure the lower number is now actually there (reduced about 40% from the original report) and I'll give this a test later tonight (I'm working on a blocker bug right now in the product I develop).

Comment 5

[Dan Mills [:thunder]]

Thanks Ray!

Comment 6

[Ray Mullins]

My apologies...I haven't forgotten about this.  Things have been slightly hectic, as you may have guessed.

I will try to get to this this weekend; if not, then next week.

Comment 7

[Dan Mills [:thunder]]

No worries.  Thanks for your help.

Comment 8

[Dominique Quatravaux]

Ray, try disabling the syncing of tabs (in Preferences... -> Weave -> Data).  If this suggestion solves your problem, then please close this bug, marking it a duplicate of bug #475314.  Thanks!

Comment 9

[Dan Mills [:thunder]]

Hey Ray,

I just released 0.2.99, which might help your problem... though I don't think so.  I did make some changes which should have small memory improvements--basically I made the internal record data structures (one per outgoing/incoming item) a bit smaller.

Let me know what you see, when you get a chance.  Thanks!

Comment 10

[Ray Mullins]

Sorry, it's been too long.

But starting somewhere around 0.2.99 the problem disappeared.  

I now have a different problem that sometimes shows up and is probably unrelated to this:

2009-02-27 14:13:56	Chrome.Window	INFO	Initializing Firefox Weave embedding
2009-02-27 14:13:56	Chrome.Window	ERROR	Could not initialize engine: Could not convert JavaScript argument arg 0 [nsISupports.QueryInterface]


But a manual sync appears to work just fine, and automatic syncs work after this.

I have a suspicion it may be related to multiple open windows, but I can't confirm that at this time.

I'm going to mark this as RESOLVED FIXED, since the memory issues are no longer a problem.

Comment 11

[Dan Mills [:thunder]]

Thanks, Ray.

We did do a lot of optimization, so it's possible we improved it enough that it's usable for you.

Also, I hope your trimmed your bookmarks a bit, 15K is a lot ;-)