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

RESOLVED FIXED in mozilla1.9alpha1

Status

()

Core
Layout
P1
normal
RESOLVED FIXED
12 years ago
11 years ago

People

(Reporter: dbaron, Assigned: dbaron)

Tracking

({fixed1.8.0.2, fixed1.8.1})

Trunk
mozilla1.9alpha1
fixed1.8.0.2, fixed1.8.1
Points:
---
Bug Flags:
blocking1.8.1 ?
blocking1.8.0.2 +

Firefox Tracking Flags

(Not tracked)

Details

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

Attachments

(2 attachments, 6 obsolete attachments)

(Assignee)

Description

12 years ago
At the Firefox Summit last week, in the session http://wiki.mozilla.org/2005Offsite/Memory_Leaks , 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)

Comment 1

12 years ago
Created attachment 205780 [details] [diff] [review]
NSPR logging code
(Assignee)

Comment 2

12 years ago
Created attachment 205781 [details]
leak-gauge.pl

Kinda ugly, but it works...
(Assignee)

Updated

12 years ago
Assignee: nobody → dbaron
Priority: -- → P1
Target Milestone: --- → mozilla1.9alpha
(Assignee)

Comment 3

12 years ago
Created attachment 205796 [details] [diff] [review]
NSPR logging code
Attachment #205780 - Attachment is obsolete: true
(Assignee)

Comment 4

12 years ago
I should really log channel implementations instead of load groups.

Timeless, do you have a reference to that NSPR logging bug?
(Assignee)

Updated

12 years ago
Whiteboard: [patch]
(Assignee)

Comment 5

12 years ago
Created attachment 205843 [details]
leak-gauge.pl
Attachment #205781 - Attachment is obsolete: true
(Assignee)

Comment 6

12 years ago
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)
(Assignee)

Comment 7

12 years ago
Created attachment 205868 [details]
leak-gauge.pl
Attachment #205843 - Attachment is obsolete: true
(Assignee)

Comment 8

12 years ago
I think the bug timeless was telling me about is bug 237326.

Comment 9

12 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

12 years ago
Perhaps your macros could also incorporate null checking gDocumentLeakPRLog :)
(Assignee)

Comment 11

12 years ago
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

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

> cat nspr7-leaky.log | perl ~/trunk/mozilla/leak-gauge.pl
URI expected at /Users/admin/trunk/mozilla/leak-gauge.pl 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 "https://bugzilla.mozilla.org/buglist.cgi?bug_status=UNCONFIRMED&bug_status=NEW&bug_status=ASSIGNED&bug_status=REOPENED&bug_status=RESOLVED&bug_status=VERIFIED&bug_status=CLOSED&field0-0-0=product&type0-0-0=substring&value0-0-0=access&field0-0-1=component&type0-0-1=substring&value0-0-1=access&field0-0-2=keywords&type0-0-2=substring&value0-0-2=access&field0-0-3=short_desc&type0-0-3=substring&value0-0-3=access&field0-0-4=status_whiteboard&type0-0-4=s

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.
(fixing nspr logging is bug 244478)
(Assignee)

Comment 14

12 years ago
Created attachment 206602 [details] [diff] [review]
NSPR logging code

without quotes
Attachment #205867 - Attachment is obsolete: true
Attachment #205867 - Flags: superreview?(darin)
Attachment #205867 - Flags: review?(jst)
(Assignee)

Comment 15

12 years ago
Created attachment 206603 [details]
leak-gauge.pl

without quotes
Attachment #205868 - Attachment is obsolete: true
(Assignee)

Updated

12 years ago
Attachment #206602 - Flags: superreview?(darin)
Attachment #206602 - Flags: review?(jst)

Updated

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

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

Comment 17

12 years ago
So I should be able to do:
SET NSPR_LOG_MODULES=DOMLeak:5
and then start firefox, rite?
(Assignee)

Comment 18

12 years ago
Wrong.  See attachment 206603 [details], which I need to figure out where to check in...

Comment 19

11 years ago
Current version of the perl script:
http://lxr.mozilla.org/mozilla/source/tools/footprint/leak-gauge.pl?raw=1

Blog entry about how to file good mlk bugs:
http://dbaron.org/log/2006-01#e20060110a

Comment 20

11 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 leak-gauge.pl 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.
(Assignee)

Comment 21

11 years ago
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

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

Comment 23

11 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.
(Assignee)

Updated

11 years ago
Status: NEW → RESOLVED
Last Resolved: 11 years ago
Flags: blocking1.8.1?
Resolution: --- → FIXED
(Assignee)

Updated

11 years ago
Attachment #206602 - Flags: approval1.8.1?
(Assignee)

Updated

11 years ago
Attachment #206602 - Flags: approval1.8.0.2?
Attachment #206602 - Flags: approval1.8.1? → branch-1.8.1?(jst)

Updated

11 years ago
Attachment #206602 - Flags: branch-1.8.1?(jst) → branch-1.8.1+
(Assignee)

Comment 24

11 years ago
Checked in to MOZILLA_1_8_BRANCH.
Keywords: fixed1.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+
(Assignee)

Comment 26

11 years ago
Fix checked in to MOZILLA_1_8_0_BRANCH.
Keywords: fixed1.8.0.2

Updated

11 years ago
Whiteboard: [patch] → [patch][nvn-dl]
You need to log in before you can comment on or make changes to this bug.