Last Comment Bug 458020 - Evaluating variables returns incorrect results
: Evaluating variables returns incorrect results
Status: RESOLVED FIXED
: fixed1.9.1, regression
Product: Core
Classification: Components
Component: JavaScript Engine (show other bugs)
: unspecified
: All All
: P2 major (vote)
: mozilla1.9.1b2
Assigned To: Blake Kaplan (:mrbkap)
:
: Jason Orendorff [:jorendorff]
Mentors:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2008-10-01 05:35 PDT by Philipp Kewisch [:Fallen]
Modified: 2009-01-22 20:11 PST (History)
16 users (show)
sayrer: blocking1.9.1+
bob: in‑testsuite-
bob: in‑litmus-
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
patch v1 (1.57 KB, patch)
2008-12-23 18:40 PST, Blake Kaplan (:mrbkap)
no flags Details | Diff | Splinter Review
patch v2 (1.78 KB, patch)
2008-12-30 17:28 PST, Blake Kaplan (:mrbkap)
brendan: review+
Details | Diff | Splinter Review
patch v3 (2.06 KB, patch)
2009-01-05 14:21 PST, Blake Kaplan (:mrbkap)
mrbkap: review+
Details | Diff | Splinter Review

Description Philipp Kewisch [:Fallen] 2008-10-01 05:35:49 PDT
When debugging javascript with venkman 0.9.87.4 on thunderbird built from comm-central (hg tip), evaluating variables gives totally different results:


STR:
1. Set a breakpoint in a random function and make the application stop there.
2. Evaluate a variable

Results, for example:

function saveReminder(item) { /* breakpoint inside */ }

* |item| /should/ be a calIItemBase
* Evaluating |item| gives:
   $[0] = [Array] [class: Array] {0}
* Evaluating |arguments[0]| (correctly) gives:
   $[1] = [XPComponent] [class: XPCWrappedNative_NoHelper] {0}
* Setting |item| to the evaluation object and evaluating this works fine.


I've heard this issue reported by other developers too, seems noone has filed a bug yet though. Its really hard to use venkman at all with this bug. Sometimes the variables evaluated are also jsd stack frames, integers, and so on.
Comment 1 :Gijs Kruitbosch 2008-10-01 07:07:56 PDT
Related to bug 449766?
Comment 2 Philipp Kewisch [:Fallen] 2008-10-01 07:31:45 PDT
Possibly the same cause, yes. Not limited to "undefined" though.
Comment 3 Frank Wein [:mcsmurf] 2008-10-01 08:16:26 PDT
This bug here is a regression though.
Comment 4 :Gijs Kruitbosch 2008-10-01 08:19:03 PDT
Great. Do you know when it regressed? And/or are you already trying to figure out?
Comment 5 Frank Wein [:mcsmurf] 2008-10-01 09:18:36 PDT
Not exactly. Old IRC logs show that the first complaints were around 2008/09/09. I wrote at that time:
<mcsmurf> looks like Venkman is now quite broken on trunk :|
<mcsmurf> the scope window in Venkman reports other variable values and types than the interactive command shell

Dunno though which output of those were wrong or if both were wrong.
Comment 6 :Gijs Kruitbosch 2008-10-01 09:25:06 PDT
(In reply to comment #5)
> Not exactly. Old IRC logs show that the first complaints were around
> 2008/09/09. I wrote at that time:
> <mcsmurf> looks like Venkman is now quite broken on trunk :|
> <mcsmurf> the scope window in Venkman reports other variable values and types
> than the interactive command shell
> 
> Dunno though which output of those were wrong or if both were wrong.

Funny. Bug 446120 is about the Watches window and Locals view disagreeing (and a bunch of errors popping up for whatever you do...

Would be good if someone could determine a regression range, and/or reliable, complete steps to reproduce...
Comment 7 Frank Wein [:mcsmurf] 2008-10-01 12:27:47 PDT
Hrm, this seems to work fine here again. Maybe Fallen can do some tests...or maybe provide a reliable way to reproduce this.
Comment 8 Philipp Kewisch [:Fallen] 2008-10-01 14:00:14 PDT
STR:

* Download/compile a thunderbird nightly
* Install venkman 0.9.87.4
* Open both, don't exclude browser files
* Open mailCore.js
* Set a breakpoint in the first possible line of CustomizeMailToolbar
* Use the context menu to trigger the breakpoint
* evaluate |toolboxId| in the interactive session

Result:
< 0001: toolboxId
> $[0] = [Array] [class: Array] {0}

Expected:
< 0001: toolboxId
> $[0] = [string] "mail-toolbox"

I'll try to find a regression range later on
Comment 9 Frank Wein [:mcsmurf] 2008-10-01 14:49:52 PDT
I think I got a regression range now, SeaMonkey build 2008-09-08 01:33:36 works fine, build from 2008-09-09 00:23:43 does not. I tested this by breaking in the function "saveImageURL" and then evaluating the imageCache var in the interactive command shell (the Local Variables view displayed the correct type/value). In the older build it displayed the usual xpconnect object, in the newer build it displayed something like "[integer] 214". 214 was the line number Venkman was currently at. When moving on with "Step Over" one line, the var evaluated to "[integer] 215".
Check-ins in that time frame: http://hg.mozilla.org/mozilla-central/pushloghtml?startdate=2008-09-08+01%3A33%3A36&enddate=2008-09-09+00%3A23%3A43
Comment 10 :Gijs Kruitbosch 2008-10-01 14:58:42 PDT
(In reply to comment #9)
> I think I got a regression range now, SeaMonkey build 2008-09-08 01:33:36 works
> fine, build from 2008-09-09 00:23:43 does not.
> Check-ins in that time frame:
> http://hg.mozilla.org/mozilla-central/pushloghtml?startdate=2008-09-08+01%3A33%3A36&enddate=2008-09-09+00%3A23%3A43

Ugh, at least half of SpiderMonkey was touched in that timeframe, there were quite a few checkins. Right now I'm suspecting http://hg.mozilla.org/mozilla-central/rev/71c48ddc9e8c (bug 454266). Cc-ing Brendan Eich. Brendan, could you please comment as to the likelihood this breakage is caused by that patch (and/or perhaps one of the other checkins in that timeframe? Thanks a lot!
Comment 11 Frank Wein [:mcsmurf] 2008-10-01 15:13:25 PDT
It looks like Bug 454266 is not the cause, tested by local back-out.
Comment 12 Frank Wein [:mcsmurf] 2008-10-01 17:33:47 PDT
BTW: I tested with a FF build, build id 2008-09-08 09:17:24 and there it was already broken. So I guess candidates for causing this bug here are Bug 446386, Bug 454163 (unlikely), Bug 453133, Bug 330237 (very unlikey).
Comment 13 Frank Wein [:mcsmurf] 2008-10-02 13:19:11 PDT
Backing out Bug 446386 locally did not have any effect, backing out Bug 453133 locally did not work, too many changes in code since that one was checked in.
Comment 14 Frank Wein [:mcsmurf] 2008-10-02 14:34:12 PDT
Igor: Could you possibly take a look at this bug here? I think it is caused by your check-in from Bug 453133. It's the only bug left from the regression range I have, I could not back it out locally though as there were too many check-ins in that code already.
If you want/need to reproduce, I suggest you either download/compile a SeaMonkey trunk build or a Firefox trunk build and install the Venkman extension (you need to hack the install.rdf file to include the Firefox trunk version). Then you open Venkman, make sure the check box under Debug->Exclude Browser Files is not checked, double-click on the file contentAreaUtils.js on the left and set a breakpoint in the function "saveImageURL" (click on the function and then click on the "-" before the line in the code view on the right). Now try to save any image on a web page by right clicking on it and clicking on "Save Image As...". Now click on "Step Over" until the "var imageCache = Components....." line has been executed. Then enter "imageCache" or "eval(imageCache)" in the command line and observe the wrong output. In the "Local Variables" window on the left the correct output should be displayed. When you enter the command, the code under http://bonsai.mozilla.org/cvsblame.cgi?file=mozilla/extensions/venkman/resources/content/venkman-commands.js&rev=1.47&mark=781#781 gets executed AFAIK.
Comment 15 Brendan Eich [:brendan] 2008-10-02 14:50:39 PDT
We need a reduced testcase. Comment 0 talks about a formal paramter named item evaluating to an Array instead of the expected XPConnect-wrapped native. I have no idea what would cause that, but it's probably not bug 453133 or anything like that bug.

/be
Comment 16 Frank Wein [:mcsmurf] 2008-10-02 16:24:40 PDT
You're right. I tried backing out again locally, Bug 446386 caused this bug here. Tested by reverting check-ins with hg revert --all -r till I found that one.
Comment 17 Brendan Eich [:brendan] 2008-10-02 16:54:42 PDT
Igor, can you take a look? Thanks,

/be
Comment 18 Frank Wein [:mcsmurf] 2008-10-21 05:55:23 PDT
Igor: Already had a chance to look into this?
Comment 19 Igor Bukanov 2008-10-21 07:36:40 PDT
(In reply to comment #18)
> Igor: Already had a chance to look into this?

I will look at this later this week.
Comment 20 Robert Sayre 2008-11-19 16:22:43 PST
any update here?
Comment 21 Daniel Glazman (:glazou) 2008-12-11 09:17:33 PST
This bug makes venkman **totally** unusable to xulrunner-based app developers
and this is a major blocker for many of us. Igor, please give a few cycles to
this bug, we really need a fix.
Comment 22 Robert Sayre 2008-12-11 13:08:20 PST
Short term fix: fix this bug.

Long term fix: regression tests for venkman/jsd.
Comment 23 timeless 2008-12-23 14:34:57 PST
fwiw, ime window.eval(...) can be used as a workaround.

from memory, that's a way i've worked around the loss of frames because of previous things. (a couple of years ago, some other flag)
Comment 24 Blake Kaplan (:mrbkap) 2008-12-23 18:40:18 PST
Created attachment 354366 [details] [diff] [review]
patch v1

The problem here is that in between the script executing, a venkman script with the same staticDepth executes and continues to execute through the call to JS_EvaluateInStackFrame, so when we compile the DEBUGGER frame, we properly compute the upvar depth, but cx->display is wrong.

This patch is correct for the time being since we only do upvars for the immediate script, and so we don't have to worry about cx->display[fp->script->staticDepth+...]. I don't know if brendan's new upvar work in bug 452498 would fix this as well.
Comment 25 Blake Kaplan (:mrbkap) 2008-12-23 18:45:08 PST
Oh, and another workaround is to, instead of evaluating |someVar| to evaluate |with ({}) someVar| to stymie the emitter's upvar optimization.
Comment 26 Daniel Glazman (:glazou) 2008-12-29 09:04:15 PST
(In reply to comment #24)
> Created an attachment (id=354366) [details]
> patch v1
> 
> The problem here is that in between the script executing, a venkman script with
> the same staticDepth executes and continues to execute through the call to
> JS_EvaluateInStackFrame, so when we compile the DEBUGGER frame, we properly
> compute the upvar depth, but cx->display is wrong.
> 
> This patch is correct for the time being since we only do upvars for the
> immediate script, and so we don't have to worry about
> cx->display[fp->script->staticDepth+...]. I don't know if brendan's new upvar
> work in bug 452498 would fix this as well.

Works absolutely fine. I patched my tree with it and at least Venkman is
now usable again until a fix gets into the trunk. Thanks a lot Blake !
Comment 27 Brendan Eich [:brendan] 2008-12-30 15:41:12 PST
Comment on attachment 354366 [details] [diff] [review]
patch v1

Common script and test

    if (script->staticDepth < JS_DISPLAY_SIZE)

around display indexing, and r=me.

/be
Comment 28 Blake Kaplan (:mrbkap) 2008-12-30 17:28:46 PST
Created attachment 354904 [details] [diff] [review]
patch v2

I wasn't sure if it was worth commoning the extra oldscript->staticDepth comparison.
Comment 29 Brendan Eich [:brendan] 2008-12-30 17:37:35 PST
Comment on attachment 354904 [details] [diff] [review]
patch v2

>     script = js_CompileScript(cx, scobj, fp, JS_StackFramePrincipals(cx, fp),
>                               TCF_COMPILE_N_GO |
>                               TCF_PUT_STATIC_DEPTH(fp->script->staticDepth + 1),
>                               chars, length, NULL,
>                               filename, lineno);
>     if (!script)
>         return JS_FALSE;
> 
>+    /* Ensure that the display is up to date for this particular stack frame. */
>+    oldscript = fp->script;

Common oldscript fully -- I see fp->script->... above in the js_CompileScript call's params.

>+    if (oldscript->staticDepth < JS_DISPLAY_SIZE) {
>+        disp = &cx->display[fp->script->staticDepth];
>+        displaySave = *disp;
>+        *disp = fp;
>+    }
>     ok = js_Execute(cx, scobj, script, fp, JSFRAME_DEBUGGER | JSFRAME_EVAL,
>                     rval);
>+    if (oldscript->staticDepth < JS_DISPLAY_SIZE)
>+        *disp = displaySave;

Is GCC gonna whine about disp being used but not always initialized? It genuinely can't assume oldscript->staticDepth is const, even though it is (C++ can help here; later).

One way out: set disp = NULL in an else clause for the first if (oldscript->staticDepth < JS_DISPLAY_SIZE) and just test if (disp) in the second if-then.

r=me with these.

/be
Comment 30 Blake Kaplan (:mrbkap) 2009-01-05 14:21:52 PST
Created attachment 355461 [details] [diff] [review]
patch v3

This should be warning free and correct.

Daniel, does the offer of French chocolate[1] stand for MoCo employees as well? :)

[1] http://www.glazman.org/weblog/dotclear/index.php?post/2008/12/11/Hard-times-for-Venkman-users-on-mozilla-central
Comment 31 Daniel Glazman (:glazou) 2009-01-05 14:24:39 PST
(In reply to comment #30)

> Daniel, does the offer of French chocolate[1] stand for MoCo employees as well?
> :)

Of course !-) Let me check tomorrow the US FDA requirements. I don't want
the chocolates to be blocked at customs and destroyed...
Comment 32 Blake Kaplan (:mrbkap) 2009-01-06 12:03:43 PST
http://hg.mozilla.org/mozilla-central/rev/965b2068588d and http://hg.mozilla.org/mozilla-central/rev/7658f9a1f671 ... I'll get this in on 1.9.1 in a couple of days.

Note You need to log in before you can comment on or make changes to this bug.