better way for users/testers to detect and isolate leaks of large object graphs

RESOLVED FIXED in mozilla1.9alpha1



13 years ago
13 years ago


(Reporter: dbaron, Assigned: dbaron)


({fixed1.8.0.2, fixed1.8.1})

fixed1.8.0.2, fixed1.8.1
Bug Flags:
blocking1.8.1 ?
blocking1.8.0.2 +

Firefox Tracking Flags

(Not tracked)


(Whiteboard: [patch][nvn-dl], URL)


(2 attachments, 6 obsolete attachments)

20.79 KB, patch
: review+
: superreview+
Details | Diff | Splinter Review
7.47 KB, text/plain; charset=utf-8
At the Firefox Summit last week, in the session , I discussed better ways for users/testers to find leaks and reduce testcases for leaks.  I'm attaching a way to do this that has some PR-logging code and a perl script to post-process the NSPR logs.  So far I'm just logging four classes.  One of those four is often entrained in leaks of large object graphs, and they all provide a good way to log URIs associated with the leaks.  This means a user can browse for a long time (as normal), run the perl script over the log, and then determine at least which pages were associated with leaks.  The user could then repeat the logging while testing those pages more carefully to get to exact steps to reproduce.

timeless says he has a patch that will allow multiple calls to PR_NewLogModule with the same string to work correctly.  That would make this a little cleaner...
Assignee: nobody → dbaron
Priority: -- → P1
Target Milestone: --- → mozilla1.9alpha
I should really log channel implementations instead of load groups.

Timeless, do you have a reference to that NSPR logging bug?
Created attachment 205867 [details] [diff] [review]
NSPR logging code

Without the nsLoadGroup stuff, since I decided it's probably not much use.  (I thought we cancel the loadgroup when we leave a page, which would remove most evidence of leaked channels, although I can't actually find any code that does that.)
Attachment #205796 - Attachment is obsolete: true
Attachment #205867 - Flags: superreview?(darin)
Attachment #205867 - Flags: review?(jst)

Comment 9

13 years ago
Comment on attachment 205867 [details] [diff] [review]
NSPR logging code

Can I encourage you to define LOG and LOG_TEST macros to clean up the code?

#define LOG(args) PR_LOG(gDocumentLeakPRLog, PR_LOG_DEBUG, args)
#define LOG_TEST() PR_LOG_TEST(gDocumentLeakPRLog, PR_LOG_DEBUG)

We do this in a bunch of other places, and IMO the result is a lot more friendly on the eyes ;-)

Comment 10

13 years ago
Perhaps your macros could also incorporate null checking gDocumentLeakPRLog :)
I tend to think it's not worth it since I'm using PR_LOG_TEST separately in about half the calls, and I couldn't use such a macro there without adding a larger performance cost to the non-logging case.

Comment 12

13 years ago
The first time I tried to use this tool, it died :(

> cat nspr7-leaky.log | perl ~/trunk/mozilla/
URI expected at /Users/admin/trunk/mozilla/ line 130, <> line 767.

The perl script is trying to do:

                    $rest =~ /^ "(.*)"$/ || die "URI expected";

But the line in the log got cut off and doesn't have a closing quote:

-1610551960[1306bf0]: DOCUMENT 26b60400 StartDocumentLoad "

I think the problem is that PR_LogPrint uses a small, fixed-length buffer, presumably because snprintf requires a fixed-length buffer.

I guess you could either remove the quotes, make the perl script tolerate missing end-quotes, or fix  PR_LogPrint.


13 years ago
Attachment #206602 - Flags: superreview?(darin) → superreview+
Comment on attachment 206602 [details] [diff] [review]
NSPR logging code

Attachment #206602 - Flags: review?(jst) → review+

Comment 17

13 years ago
So I should be able to do:
and then start firefox, rite?

Comment 20

13 years ago
Three more problems, then I think I'll stop whining:

* On Windows, each line of the log file starts with "0" rather than a large negative number.  Since the Perl script expects each line to start with a hyphen, this breaks it completely.  Suggested fix:

-    if (/^\-[0-9]*\[[0-9a-f]*\]: (\S*) (.*)$/) {
+    if (/^\-?[0-9]*\[[0-9a-f]*\]: (\S*) (.*)$/) {

* On Windows, if I don't run dos2unix on the log file before running leak-gauge, leak-gauge says "outer expected at line 89, <> line 3" and dies.

* There are several situations in which the perl script doesn't print anything.  It should say "I can't make sense of this log file :(" or "No leaks of documents, docshells, or domwindows detected :)" instead of being silent and possibly misleading.
Both windows bugs fixed (one based on your suggestion, one based on actual testing of a file with CR-LF line endings), and summary stats added at the end, whether or not there were leaks.  See revision 1.5.

Comment 22

13 years ago
Awesome.  It works well on Windows now.

Comment 23

13 years ago
It would be nice if this would rename the file at startup instead of clobbering it, so more than one run's worth of data can be processed at once. (And so you don't accidentally lose anything by restarting the browser.)

If this is done it would be good for the script to actually tell whether the browser crashed or it's a legitimate leak, as a human more than likely won't be able to remember what happened when in previous runs.
Last Resolved: 13 years ago
Flags: blocking1.8.1?
Resolution: --- → FIXED


13 years ago
Attachment #206602 - Flags: approval1.8.1? → branch-1.8.1?(jst)
Attachment #206602 - Flags: branch-1.8.1?(jst) → branch-1.8.1+
Flags: blocking1.8.0.2+
Comment on attachment 206602 [details] [diff] [review]
NSPR logging code

approved for 1.8.0 branch, a=dveditz
Attachment #206602 - Flags: approval1.8.0.2? → approval1.8.0.2+
Whiteboard: [patch] → [patch][nvn-dl]
You need to log in before you can comment on or make changes to this bug.