109652 - Venkman needs to profile

Status: VERIFIED FIXED

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

Description

[Peter Van der Beken [:peterv]]

I want to enable the xpctools stuff per file and maybe even per function.

Comment 1

[Robert Ginda]

P1 because it requires changes to native code.

Comment 2

[Robert Ginda]

Native support should make 1.0, UI may take longer.

Comment 3

[Robert Ginda]

Attachment: jsd patch, round one

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.

Comment 4

[Robert Ginda]

Attachment: correct jsd patch

last patch was the wrong one, here's the right one.

Comment 5

[Robert Ginda]

Attachment: extensions/venkman diff

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.

Comment 6

[Robert Ginda]

Adding potential reviewers.  Patch isn't ready for final review yet, but
comments would be welcome.  Especially from you, jband.

Comment 7

[Robert Ginda]

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.

Comment 8

[Robert Ginda]

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".

Comment 9

[Robert Ginda]

I'm going to shoot for 0.9.9, looking for tester help.

Comment 10

[Fabian Guisset]

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.

Comment 11

[Fabian Guisset]

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!

Comment 12

[Bob Clary [:bc] (inactive)]

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.

Comment 13

[Robert Ginda]

Attachment: updated jsd patch, changed jsdService::clearAllProfileData to clearProfileData

Comment 14

[Robert Ginda]

Attachment: I did it again, here is the correct jsd patch

Comment 15

[Robert Ginda]

Attachment: updated e/venkman diff

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.

Comment 16

[John Bandhauer]

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).

Comment 17

[Brendan Eich [:brendan]]

Just use strdup, no XP reason for PL_strdup now (or ever?  I forget).

/be

Comment 18

[Robert Ginda]

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.

Comment 19

[Robert Ginda]

Attachment: latest e/venkman patches

UI Patches adds Save As, Open URL, Open File menu items, adds a Profile top
level menu, and a Profile toolbar.

Comment 20

[Robert Ginda]

Attachment: new images as a tar.gz

unzip this tar.gz in venkman/resources/skin/images

Comment 21

[Robert Ginda]

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 22

[Brendan Eich [:brendan]]

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=[e-mail].

/be

Comment 23

[Robert Ginda]

> 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?

Comment 24

[Robert Ginda]

Attachment: new jsd patch

New jsd patch reports profile data in mircoseconds instead of milliseconds. 
Data is still stored in a long.

Comment 25

[Robert Ginda]

Attachment: better e/venkman patches

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.

Comment 26

[Robert Ginda]

Attachment: 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.

Comment 27

[Robert Ginda]

Attachment: jsd patches, best ever

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.

Comment 28

[Robert Ginda]

Attachment: e/venkman, back to milliseconds in getProfileSummary

Comment 29

[Robert Ginda]

Attachment: e/venkman changes, all done?

I missed a spot in the jar.mn

Comment 30

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

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.

Comment 31

[Robert Ginda]

peterv tested this on a mac, probably OS X, without any string issues.

Comment 32

[Robert Ginda]

Attachment: jsd patch - not 64bit struct safe

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.

Comment 33

[timeless]

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

Comment 34

[Robert Ginda]

Attachment: jsd patches

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.

Comment 35

[Robert Ginda]

Attachment: js/src/ changes

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.

Comment 36

[Robert Ginda]

peterv pointed out I should be using JSInt64 instead of int64, I've got the
changes here.

Comment 37

[Brendan Eich [:brendan]]

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

Comment 38

[Brendan Eich [:brendan]]

s/PRUint32/JSUint32/ in my first sentence.

/be

Comment 39

[Peter Van der Beken [:peterv]]

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

r=peterv with JSInt64 and exec*u*tion.

Comment 40

[Robert Ginda]

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.

Comment 41

[Brendan Eich [:brendan]]

New patch for the minimal, native (C code) changes?

/be

Comment 42

[Robert Ginda]

Attachment: smaller js/src patch

use int64 instead of JSInt64, don't touch jsdate.[ch], and forget about the
jsinterp.c changes.

Comment 43

[Robert Ginda]

Attachment: one more time, jsd changes

add jsdIScript::version attribute, compensate for pc's with a 0 value.

Comment 44

[Brendan Eich [:brendan]]

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

Comment 45

[Peter Van der Beken [:peterv]]

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 ...)

Comment 46

[Robert Ginda]

I forgot to fix JSInt64 usage in jsd.h, taken care of.

Comment 47

[Peter Van der Beken [:peterv]]

Comment on attachment 71389 [details] [diff] [review]
one more time, jsd changes

r=peterv.

Comment 48

[Peter Van der Beken [:peterv]]

Comment on attachment 71387 [details] [diff] [review]
smaller js/src patch

r=peterv

Comment 49

[Robert Ginda]

Thanks peterv and brendan.
Shaver, got time to sr= the rest?

Comment 50

[Brendan Eich [:brendan]]

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

Comment 51

[Robert Ginda]

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 52

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

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.

Comment 53

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

Comment on attachment 71269 [details] [diff] [review]
e/venkman changes, all done?

sr+a=shaver for 0.9.9

Comment 54

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

Comment on attachment 71387 [details] [diff] [review]
smaller js/src patch

a=shaver for 0.9.9.

Comment 55

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

Comment on attachment 71389 [details] [diff] [review]
one more time, jsd changes

a=shaver for 0.9.9

Comment 56

[Robert Ginda]

Fixed checked in.

Comment 57

[Christopher Aillon (sabbatical, not receiving bugmail)]

vrfy fixed.  may JS execution time decrease with developers' good usage of this
tool.