Closed Bug 109652 Opened 23 years ago Closed 22 years ago

Venkman needs to profile

Categories

(Other Applications Graveyard :: Venkman JS Debugger, defect, P1)

defect

Tracking

(Not tracked)

VERIFIED FIXED
mozilla0.9.9

People

(Reporter: peterv, Assigned: rginda)

Details

(Whiteboard: [native])

Attachments

(4 files, 15 obsolete files)

14.64 KB, application/octet-stream
Details
59.42 KB, patch
peterv
: review+
shaver
: superreview+
shaver
: approval+
Details | Diff | Splinter Review
2.39 KB, patch
peterv
: review+
brendan
: superreview+
shaver
: approval+
Details | Diff | Splinter Review
33.35 KB, patch
peterv
: review+
shaver
: superreview+
shaver
: approval+
Details | Diff | Splinter Review
I want to enable the xpctools stuff per file and maybe even per function.
P1 because it requires changes to native code.
Status: NEW → ASSIGNED
Priority: -- → P1
Native support should make 1.0, UI may take longer.
Whiteboard: [native]
Target Milestone: --- → mozilla1.0
Attached patch jsd patch, round one (obsolete) — Splinter Review
changes to js/jsd.  Not ready for check in yet, but I'd appreciate comments.
This diff includes the diffs in bug 121505 and bug 121925.

The idea is that I've added a JSDProfileData struct to hold profile info,
intorduced flags in jsdscripts, and augmented the jsdcontext flags.

A jsdscript's flags control whether or not the script should be profiled and/or
debugged.  The logic can be switched by context flags.	i.e.  If the context's
JSD_PROFILE_IF_SET flag is set, and the script's JSD_SCRIPT_PROFILE_BIT is set
then profile info is collected.  Data is also collected if JSD_PROFILE_IF_SET
is clear and JSD_SCRIPT_PROFILE_BIT is also clear.  This will allow to select
whether they'd like to have a profile whitelist or blacklist.

Similar functionality is available via JSD_DEBUG_IS_SET and
JSD_SCRIPT_DEBUG_BIT.  This debug bit may supplant the jsdIFilter interface
post 1.0, but I'll leave them both in for now.

Profile information is only collected when the JSD_COLLECT_PROFILE_DATA context
flag is set.

This adds NSPR dep to jsd.  I'm not going to check it in like that (jsd is used
in some nspr-less embeddings.)	I think the best solution is to export a
JS_GetNowMS() entrypoint from js/src.  I'll deal with that RSN.
Attached patch correct jsd patch (obsolete) — Splinter Review
last patch was the wrong one, here's the right one.
Attachment #70956 - Attachment is obsolete: true
Attached patch extensions/venkman diff (obsolete) — Splinter Review
Patch adds some UI for profile data collection.  Profile data is collected for
*all* scripts at the moment, I'll add a way to tweak the profile mask later.

Debug->Collect Profile Data and the console command "profile" can be used to
toggle the JSD_COLLECT_PROFILE_DATA flag.
The console command "clear-profile" can be used to zero out the profile data.
The console command "dumpprofile [<file-name>]" can be used to dump profile
data for a single file, or all data collected.
"Dump Profile Data" is also available from the context menu on the script view.


dumpprofile and "Dump Profile Data" currently dump to the console, I may try to
make some pretty HTML later today.

Please try this out and let me know how it goes.
Adding potential reviewers.  Patch isn't ready for final review yet, but
comments would be welcome.  Especially from you, jband.
QA Contact: rginda → caillon
sample output from dumpprofile:
vnk: function: feedback, total 17 (0), calls 1, min 17, max 17, avg 17
vnk: function: display, total 17 (0), calls 1, min 17, max 17, avg 17
vnk: function: onload, total 23 (0), calls 1, min 23, max 23, avg 23
vnk: function: con_tabcomplete, total 27 (0), calls 1, min 27, max 27, avg 27
vnk: function: torr_resort, total 131 (0), calls 3, min 131, max 131, avg 43.67
vnk: function: cmdTreeTest, total 64 (0), calls 1, min 64, max 64, avg 64
vnk: function: con_winload, total 134 (0), calls 1, min 134, max 134, avg 134
vnk: function: tov_thaw, total 134 (0), calls 1, min 134, max 134, avg 134

total, min, max, and avg are call times, in ms.  the number in parens is the
recurse count (this taints the data a bit).  calls is the number of times the
function was called.
I forgot to mention that the file that defines "dumpprofile" isn't loaded by
default.

To load it, type "loadd chrome://venkman/content/venkman-dev.js"
To have it loaded at startup automatically, type "pref initialScripts
chrome://venkman/content/venkman-dev.js".
I'm going to shoot for 0.9.9, looking for tester help.
Target Milestone: mozilla1.0 → mozilla0.9.9
I tried the patch and it built fine. However it seems the dumpprofile command
was not implemented. Typing "dumpprofile" in the js debugger gives "No such
command, "dumpprofile"".
profile on/off works fine. When closing venkman, I get
<top>
anonymous@47
con_winunload@110
wwObserve@44
[anonymous]@0

but I don't know what it means. Apart from not being able to get the profile
data, it seems it doesn't cause any problem and venkman still works fine.
Ok with rginda's help I got it to work (I should RTFM), and it seems to work
really great. Got dhtml profile data easily. Didn't crash so far. Excellent!
I can occasionally lock up the browser after visiting several pages, dumping the
profile, clearing, etc. It is not consistent behavior however. I was
experimenting using http://developer.netscape.com/evangelism/ and the scripts
located there. I will try to find a reproducible test case and report back.
Attachment #70962 - Attachment is obsolete: true
Attachment #71077 - Attachment is obsolete: true
Attached patch updated e/venkman diff (obsolete) — Splinter Review
This patch adds the "save-profile" command, which allows you to save profile
data as a human readable text file, or a CSV file.  Choosing "Save Profile
Data" from the scripts view context menu saves only the data for that
particular file.  Debug->Profile->Save Profile Data saves it all.

Please try these out and post results.
Attachment #70963 - Attachment is obsolete: true
Both patches look good to me sr= wise. Looks like we're waiting on more testing,
right? FWIW, I'm not a big fan of using PL_strdup to constuct interface 'out'
strings. But that is probably a losing battle (for now).
Just use strdup, no XP reason for PL_strdup now (or ever?  I forget).

/be
I've changed to strdup here.  I think I'm ready for final r/sr.  If this patch
does introduce some hard-to-reproduce hang, that's exactly the kind of thing I'd
like to use 0.9.9 testers to track down.  It's not busted out of the box, and bc
may have run into issues with loading urls over http.

Brendan, can you a= too?  I'll send mail to drivers now.
Attached patch latest e/venkman patches (obsolete) — Splinter Review
UI Patches adds Save As, Open URL, Open File menu items, adds a Profile top
level menu, and a Profile toolbar.
Attachment #71079 - Attachment is obsolete: true
Attached file new images as a tar.gz (obsolete) —
unzip this tar.gz in venkman/resources/skin/images
Here is a sample profile log taken while running chatzilla:
http://www.hacksrus.com/~ginda/venkman/chatzilla.profile

And here is a screenshot of the new UI:
http://www.hacksrus.com/~ginda/venkman/screenshots/venkman-20020223.gif
Comment on attachment 71153 [details] [diff] [review]
latest e/venkman patches

>+futils.getPicker =
>+function futils_nosepicker(initialPath, typeList, attribs)

Nice!

>+    if (typeof attribs == "object")
>+    {
>+        for (var a in attribs)
>+            picker[a] = attribs[a];
>+    }

Do you want to do anything with attribs if it's not an object?	Just wonderin'.

>+    if (typeList instanceof Array)
>+    {
>+        var mask;

It looks like mask is unused.

>+function pickSaveAs (title, typeList, defaultFile, defaultDir)
>+{
>+    if (!defaultDir && "lastSaveAsDir" in futils)
>+        defaultDir = futils.lastSaveAsDir;
>+    
>+    var picker = futils.getPicker (defaultDir, typeList, 
>+                                   {defaultString: defaultFile});
>+    picker.init (window, title ? title : futils.MSG_SAVE_AS,
>+                 Components.interfaces.nsIFilePicker.modeSave);
>+
>+    var rv = picker.show();
>+    
>+    if (rv != PICK_CANCEL)
>+        futils.lastSaveAsDir = picker.file.parent;
>+
>+    return {reason: rv, file: picker.file, picker: picker};
>+}
>+
>+function pickOpen (title, typeList, defaultFile, defaultDir)
>+{
>+    if (!defaultDir && "lastOpenDir" in futils)
>+        defaultDir = futils.lastOpenDir;
>+    
>+    var picker = futils.getPicker (defaultDir, typeList, 
>+                                   {defaultString: defaultFile});
>+    picker.init (window, title ? title : futils.MSG_OPEN,
>+                 Components.interfaces.nsIFilePicker.modeOpen);
>+
>+    var rv = picker.show();
>+    
>+    if (rv != PICK_CANCEL)
>+        futils.lastOpenDir = picker.file.parent;
>+
>+    return {reason: rv, file: picker.file, picker: picker};
>+}

It'd be easy to combine these into one function, or make a common subroutine,
via some extra params ("lastOpenDir", etc.).  Just a thought.

>+LocalFile.prototype.read =
>+function fo_read(max)
>+{
>+    var av = this.inputStream.available();
>+    if (typeof max == "undefined")
>+        max = av;
>+
>+    if (!av)
>+        return null;
>+    
>+    dd ("file.read: available " + av);
>+
>+    if (!("inputStream" in this))
>+        throw "file not open for reading.";

Don't you want to do this check first thing, esp. before the available call?

>+    
>+    var rv = this.inputStream.read(max);
>+    dd ("file.read: returning " + rv);
>+    return rv;
>+}
>@@ -566,11 +598,25 @@
>     if (!e.url)
>     {
>         console.sourceView.displaySourceText(null);
>-        return true;
>+        return null;
>     }
>     
>     var sourceText;
>     
>+    if (e.url.indexOf("x-jsd:") == 0)
>+    {
>+        if (e.url == "x-jsd:help")
>+        {
>+            dispatch ("help");
>+            return e.url;
>+        }
>+        else

else after return, bleah.

>+function cmdFindFile (e)
>+{
>+    if (!e.fileName || e.fileName == "?")
>+    {
>+        var fileName = console.sourceView.childData.fileName;
>+        if (!fileName.search(/^\w+:/))

You want to test for a < 0 or -1 return here (< 0 is faster) -- search can
return 0 on match (if the regexp matches starting at index 0 in the target
string).

>+
>+function cmdSaveSource (e)
>+{
>+    if (!e.targetFile || e.targetFile == "?")
>+    {
>+        var fileName = console.sourceView.childData.fileName;
>+        if (!fileName.search(/^\w+:/))

Ditto.

>+++ resources/content/venkman-handlers.js	24 Feb 2002 04:38:40 -0000
>@@ -46,20 +46,36 @@
> 
>     console.wwObserver = {observe: wwObserve};
>     console.windowWatcher.registerNotification (console.wwObserver);
>+    console.windows.hookedWindows = new Array();
>+
>+    var enumerator = console.windowWatcher.getWindowEnumerator();
>+    while (enumerator.hasMoreElements())
>+    {
>+        var win = enumerator.getNext();
>+        if (win.location.href != "chrome://venkman/content/venkman.xul")
>+        {
>+            console.onWindowOpen(win);
>+            console.onWindowLoad();

Do you want to break here, or could there be several venkman windows open?  If
so, can console.onWindowOpen remember them all?

>+    function addScriptRec(s)
>+    {
>+        var obj = new Object();
>+        obj.total = s.script.totalExecutionTime;
>+        obj.ccount = s.script.callCount;
>+        obj.avg = roundTo(obj.total / obj.ccount, 2);
>+        obj.min = s.script.minExecutionTime;
>+        obj.max = s.script.maxExecutionTime;
>+        obj.recurse = s.script.maxRecurseDepth;
>+        obj.path = s.script.fileName;
>+        obj.file = getFileFromPath(obj.path);
>+        obj.base = s.script.baseLineNumber;
>+        obj.end = obj.base + s.script.lineExtent;
>+        obj.fun = s.functionName;
>+        obj.str = obj.fun  + ":" + obj.base + "-" + obj.end +
>+            ", calls " + obj.ccount +
>+            (obj.recurse ? " (depth " + obj.recurse +")" : "") +
>+            ", total " + obj.total + 
>+            "ms, min " + obj.min +
>+            "ms, max " + obj.max +
>+            "ms, avg " + obj.avg + "ms.";

Why not an object literal?

>+        list.push (obj);
>+    };
> function arrayIndexOf (ary, elem)
> {
>+    if (!ary)
>+        return -1;
>+    
>     for (var i in ary)
>         if (ary[i] == elem)
>             return i;

Does anyone use this, or arrayContains (itsonly caller, AFAICT)? Ditch 'em if
not.  If they are needed and ary gets long, or even if not, an associative
scheme seems better.

Fix these issues and pick whatever nits you agree with, and
sr=brendan@mozilla.org.

/be
Attachment #71153 - Flags: superreview+
> Do you want to do anything with attribs if it's not an object?  Just wonderin'.

Yeah, I'll throw an exception.

> It looks like mask is unused.

Fixed.

> It'd be easy to combine these into one function, or make a common subroutine,
> via some extra params ("lastOpenDir", etc.).  Just a thought.

If pickOpen and pickSaveAs are the only two clients, I think I prefer the
cut-and-pasting for readability.  I'll refactor if another pickFoo gets written.

> Don't you want to do this check first thing, esp. before the available call?

Yeah, fixed that.  My else clause in fopen neglected to open the output stream
in the file was opened read/write, I fixed that too.

> else after return, bleah.

Oops, fixed.

> You want to test for a < 0 or -1 return here (< 0 is faster) -- search can
> return 0 on match (if the regexp matches starting at index 0 in the target
> string).

d'oh.

> Do you want to break here, or could there be several venkman windows open?  If
> so, can console.onWindowOpen remember them all?

Only one chrome://content/venkman/venkman.xul can ever be open.  Bad Things
would happen if a user were to manage to get two of them open at once.

> Why not an object literal?

Fixed.

> Does anyone use this, or arrayContains (itsonly caller, AFAICT)? Ditch 'em if
> not.  If they are needed and ary gets long, or even if not, an associative
> scheme seems better.

I use it at the console sometimes, in debug functions, and in some prototype
code, but rarely in "real" code.  I try to stay away from using it, but
sometimes it comes in handy.

Thanks for the review, anything to say about the native changes, or does that
sr= cover both attachments?












Attached patch new jsd patch (obsolete) — Splinter Review
New jsd patch reports profile data in mircoseconds instead of milliseconds. 
Data is still stored in a long.
Attachment #71078 - Attachment is obsolete: true
Attached patch better e/venkman patches (obsolete) — Splinter Review
Takes into account new profile data units, incorperates brendan's suggestions,
adds pretty print toolbar button.

Also, I found out that it's reasonably likely that a script will be collected
while in the body of addScriptRecord (in
venkman-static.js:con_getProfileSummary.)  When this happens, accessing some of
the properties on that script will throw and exception.  I now catch the
exception and spew a "Lost profile data for url:function" warning to the
debugger console when this happens.
Attachment #71153 - Attachment is obsolete: true
Attached file all images
Tarball containing the new prettyprint icons, and the previously posted profile
icons.

That last venkman patch also fixes a jar.mn problem pointed out by peterv.
Attachment #71154 - Attachment is obsolete: true
Attached patch jsd patches, best ever (obsolete) — Splinter Review
After saying "Data is still stored in a long" I realized that the data never
was stored in a long.  It's a double, and it can be fractional.  This patch
does the usec to msec conversion on the native side of town, and leaves the
rounding to js.
Attachment #71251 - Attachment is obsolete: true
Attachment #71254 - Attachment is obsolete: true
I missed a spot in the jar.mn
Attachment #71257 - Attachment is obsolete: true
strdup, FWIW, isn't part of ANSI (SVID3, BSD4.3), and for some time wasn't
available on the Mac.  PL_strdup is one of the few PL_str* functions (along with
PL_strcasecmp) that actually may still have value.
peterv tested this on a mac, probably OS X, without any string issues.
My usec to msec conversion divided a double by 1000.  I think this was the
cause of occasional negative numbers in the results, and have changed the
literal to 1000.0.  This seems to have cleaned up the data.

Also, peterv pointed out that the new macros took |script| as an argument but
worked on |jsdscript|.	And the indentation was wrong.
Attachment #71256 - Attachment is obsolete: true
Comment on attachment 71311 [details] [diff] [review]
jsd patch - not 64bit struct safe

rginda is going to introduce a JS_Now and fix some int64 code to use JSLL_ /
JS_Now
Attachment #71311 - Attachment description: final jsd patch, really. → jsd patch - not 64bit struct safe
Attachment #71311 - Flags: needs-work+
Attached patch jsd patches (obsolete) — Splinter Review
Previous patch had problems mixing PRTime with int64 on platforms with int64
structs.

Switch to JS_Now.
Use JSLL_ZERO and JSLL_IS_ZERO macros instead of direct assignments.
s/strdup/PL_strdup/ per #mozilla discussion with jag.
Attachment #71311 - Attachment is obsolete: true
Attached patch js/src/ changes (obsolete) — Splinter Review
Adds JS_Now() to jsapi.h, and JS_GetScriptVersion() to jsdbgapi.h.

Also includes the fixes for bug 126988.  Fixing this make venkman behave when
the user "steps over" past the end of a funciton, where the fact that we get a
call-end hook without a call-start hook matters.  If this change is
controversial maybe it can wait for 1.0.
peterv pointed out I should be using JSInt64 instead of int64, I've got the
changes here.
No, the JS engine uses uint32, not PRUint32, in general -- although fur dragged
in too much NSPR (IMHO) when he got rid of js/ref.  Please don't infect the API
with JSUint64.

I don't see why the public API needs a JS_Now, *and* jsdate.c needs to export a
js_Now library-private too.  Can we save a little code footprint, please?

This all duplicates NSPR code, leading me to ask: what next?  I really don't
want to see JSThread or JSIntervalTime.  Reassure me.

/be
s/PRUint32/JSUint32/ in my first sentence.

/be
Comment on attachment 71342 [details] [diff] [review]
jsd patches

r=peterv with JSInt64 and exec*u*tion.
Attachment #71342 - Flags: review+
JS_Now() gives you information you could get by creating a new date object and
converting it to a number, with less overhead and more precision. 
JS_IntervalTime could be rejected on the grounds that it adds new functionality,
and is not currently required by the engine.

There is no way around the fact that any stand alone js implementation will need
a some sort of "now" function.  Why not provide clients access to it?

I exported js_Now from jsdate to avoid a #include "prmjtime.h" in jsapi.c, but
I'll be happy to move it.
New patch for the minimal, native (C code) changes?

/be
use int64 instead of JSInt64, don't touch jsdate.[ch], and forget about the
jsinterp.c changes.
Attachment #71344 - Attachment is obsolete: true
add jsdIScript::version attribute, compensate for pc's with a 0 value.
Attachment #71342 - Attachment is obsolete: true
Comment on attachment 71387 [details] [diff] [review]
smaller js/src patch

sr=me, thanks.	shaver's your man for all other sr= work here, and for this
week if you wanted me!

/be
Attachment #71387 - Flags: superreview+
Comment on attachment 71269 [details] [diff] [review]
e/venkman changes, all done?

r=peterv with the small changes i discussed with you. I prefer you using your
constants over 0666 and 0022 (but I'm just a Mac guy and I have never heard of
permissions ...)
Attachment #71269 - Flags: review+
I forgot to fix JSInt64 usage in jsd.h, taken care of.
Comment on attachment 71389 [details] [diff] [review]
one more time, jsd changes

r=peterv.
Attachment #71389 - Flags: review+
Comment on attachment 71387 [details] [diff] [review]
smaller js/src patch

r=peterv
Attachment #71387 - Flags: review+
Thanks peterv and brendan.
Shaver, got time to sr= the rest?
Re: comment #32 -- I don't see how 1000.0 or 1000. or (double)1000 as the
divisor helps, compared to 1000, if the numerator is of type double.  Both
operands will be converted to double if either is double.  What's more, the sign
of the result shouldn't change due to division by a positive number.  Is there
still a mystery here?

/be
I'm not seeing negative numbers anymore.  Maybe they got flushed out by some
other change, or maybe there is still an issue here.  I've stared at this code
for a while and don't (or can't) see a problem in the int64 calculations.

I forgot to negate JSLL_IS_ZERO(pdata->lastCallStart) in jsd_scpt.c:_callHook in
that last patch, however, which caused all the profile data to stick at 0. 
fixed here.
Comment on attachment 71389 [details] [diff] [review]
one more time, jsd changes

There are a few cases of "} else {", which goes against prevailing style. 
Also, we can probably safely rid ourselves of the #ifdef LIVEWIRE stuff, if you
go through on another pass.

sr=shaver, clean up as you desire.
Attachment #71389 - Flags: superreview+
Comment on attachment 71269 [details] [diff] [review]
e/venkman changes, all done?

sr+a=shaver for 0.9.9
Attachment #71269 - Flags: superreview+
Attachment #71269 - Flags: approval+
Comment on attachment 71387 [details] [diff] [review]
smaller js/src patch

a=shaver for 0.9.9.
Attachment #71387 - Flags: approval+
Comment on attachment 71389 [details] [diff] [review]
one more time, jsd changes

a=shaver for 0.9.9
Attachment #71389 - Flags: approval+
Fixed checked in.
Status: ASSIGNED → RESOLVED
Closed: 22 years ago
Resolution: --- → FIXED
vrfy fixed.  may JS execution time decrease with developers' good usage of this
tool.
Status: RESOLVED → VERIFIED
Product: Core → Other Applications
Product: Other Applications → Other Applications Graveyard
You need to log in before you can comment on or make changes to this bug.