Closed Bug 607764 Opened 14 years ago Closed 14 years ago

tab-browser tests throw "this._browsers is undefined" and fail "activeTab element matches"

Categories

(Core :: XPConnect, defect)

Product:
Core
Component:
XPConnect
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla2.0b7
Tracking Flags:
Tracking Status
blocking2.0 --- beta7+

People

(Reporter: myk, Assigned: gal)

References

Details

On the latest Firefox trunk nightly, tab-browser tests fail with a "TypeError: this._browsers is undefined" exception and two "error: fail: activeTab element matches (({}) != ({}))" failures.

--------------------------------------------------------------------------------
(addon-sdk)myk@myk:~/Projects/addon-sdk/packages/jetpack-core$ cfx test -F tab-browser
Using binary at '/home/myk/bin/firefox'.
Using profile at '/tmp/tmpLnLGU2.mozrunner'.

(firefox-bin:22839): GLib-WARNING **: g_set_prgname() called multiple times
......error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/timer.js", line 64, in notifyOnTimeout
    this._callback.apply(null, this._params);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 56, in 
    callback(window, browsers[0]);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 211, in 
    if (tb.length == 0)
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 203, in 
    return this._browsers.length;
TypeError: this._browsers is undefined
error: TEST FAILED: test-tab-browser.testTrackerWithoutDelegate (timed out)
....error: fail: activeTab element matches (({}) != ({}))
info: Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 138, in anonymous
    require("errors").catchAndLog(function(e) options.onLoad(e))(e);
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in anonymous
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 138, in anonymous
    require("errors").catchAndLog(function(e) options.onLoad(e))(e);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 277, in anonymous
    test.assertEqual(browser.tabContainer.getItemAtIndex(tabIndex), tabBrowser.activeTab, "activeTab element matches");
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 227, in assertEqual
    this.fail(message);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 145, in fail
    console.trace();
error: fail: activeTab element matches (({}) != ({}))
info: Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 138, in anonymous
    require("errors").catchAndLog(function(e) options.onLoad(e))(e);
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in anonymous
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 138, in anonymous
    require("errors").catchAndLog(function(e) options.onLoad(e))(e);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 282, in anonymous
    test.assertEqual(browser.tabContainer.getItemAtIndex(tabIndex), tabBrowser.activeTab, "activeTab element matches");
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 227, in assertEqual
    this.fail(message);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 145, in fail
    console.trace();
...............
25 of 28 tests passed.
FAIL
Total time: 16.623435 seconds
Program terminated unsuccessfully.
--------------------------------------------------------------------------------

These look similar to the extant failures in bug 607113 and the failure in bug 607090 that has since been resolved.

Irakli, Drew: do either of you have a sense of what might be going on here?
Blocks: 604641
No longer depends on: 604641
Myk, can you explain how this can be reproduced? Where should one pull from,
what needs to be built, etc etc?
Pull from http://github.com/mozilla/addon-sdk or its Hg mirror at
https://hg.mozilla.org/labs/jetpack-sdk/.  Then enter your local clone's
directory in a terminal and run "source bin/activate" ("bin\activate.bat" on
Windows).  Then enter packages/jetpack-core/ and run "cfx test -F tab-browser".

That command will look for Firefox, but if it doesn't find it (or if you think
it might be finding a different binary than the one you want to test with),
specify "--binary=/path/to/binary" on that command line.
Myk, when I isolate the tab-browser test with the latest Firefox nightly and current SDK tree (abd04572e9c716b97849), all tests pass.  But it says it ran 32 tests, not 28 like your log shows.  Is this another Linux-only bug?
Whoops, I was running 3.6, not trunk.  Tests pass on 3.6!  With trunk though, I only get one of your errors:

error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/timer.js", line 64, in notifyOnTimeout
    this._callback.apply(null, this._params);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 56, in 
    callback(window, browsers[0]);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 211, in 
    if (tb.length == 0)
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 203, in 
    return this._browsers.length;
TypeError: this._browsers is undefined
tab-browser.js does this:

  exports.Tracker = apiUtils.publicConstructor(Tracker);

If I make it do this instead:

  exports.Tracker = Tracker;

The error goes away.  So maybe bug 607863 really is a problem.  If that's not it, it's something like it.
This sounds a lot like bug 596031 comment 6, which Blake links to from bug 607863.  When the length getter is called on the Tracker instance tb, it's resolved to Tracker.prototype, but when Tracker.prototype's length getter is called, `this` is not tb, and tb is what _browsers is attached to.
Depends on: 607863
With the fixes for bugs 607799, 607863, 606585, and bug 608142 I pass 32 of 33 tests, here's the output:

(jetpack-sdk)[jst@gandalf jetpack-core]$ cfx test -F tab-browser --binary=/home/jst/work/tip/fb-rel/dist/bin/firefox
Using binary at '/home/jst/work/tip/fb-rel/dist/bin/firefox'.
Using profile at '/tmp/tmpZLZQH6.mozrunner'.
...........error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
....error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
.error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
.error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
......error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
...error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
..error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
.error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/errors.js", line 49, in 
    return callback.apply(this, arguments);
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 280, in eventHandler
    callback(event.target.defaultView);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 190, in 
    test.assertEqual(item.textContent, "bar",
TypeError: item is null
...error: warnings and/or errors were logged.

32 of 33 tests passed.
OK
Total time: 9.014372 seconds
Program terminated successfully.
Could someone who knows these tests construct minimized test cases that show what's actually not working here? Debugging these tests as a whole is very difficult.
I'm pretty sure this is caused by bug 596031, but I haven't tried the patch there yet.
With Blake's patch in bug 596031 the "_browsers is undefined" error is fixed, but I get the same "item is null" errors as jst in comment 7.
What's happening is the Tracker in testWhenContentLoaded is not being unloaded even though unload is called on it, so it sticks around when other tests are running, and those other tests open pages that don't have a #foo node in them.

Even with Blake's patch, something's still weird with prototypes.  If I do what comment 5 says again, the "item is null" error goes away.  testTrackerWithDelegate, which runs before testWhenContentLoaded, creates a Tracker too.  It appears that this Tracker is somehow the same Tracker object created in testWhenContentLoaded.  When Tracker objects are created, require("unload").ensure(this) is called on them, which replaces their unload methods with a new method that ensures their unload methods are called at most once.  The Tracker in testTrackerWithDelegate has its unload method called successfully, but the Tracker in testWhenContentLoaded doesn't -- as if they're the same object.
Here's a simplified test case.  Sorry it's so hard to follow.

  var sp = Components.classes["@mozilla.org/systemprincipal;1"].
           createInstance(Components.interfaces.nsIPrincipal);
  var s = Components.utils.Sandbox(sp);
  Components.utils.evalInSandbox(
    'function makePublicCtor(privateCtor) {' +
    '  function PublicCtor() {' +
    '    var obj = { __proto__: PublicCtor.prototype };' +
    '    privateCtor.apply(obj, arguments);' +
    '    return obj;' +
    '  }' +
    '  PublicCtor.prototype = { __proto__: privateCtor.prototype };' +
    '  return PublicCtor;' +
    '}',
    s
  );
  function ensure(obj) {
    var x;
    obj.f = function () {
      var curr_x = x;
      x = "foo";
      return curr_x;
    };
  }
  function Private() { ensure(this); }
  Private.prototype = { f: function () {} };
  var Public = s.makePublicCtor(Private);
  var o1 = Public();
  var o2 = Public();
  o1.f(); /* undefined, as expected */
  o2.f(); /* "foo" */

o2.f() returns undefined as expected if makePublicCtor is defined outside the sandbox or if Private.prototype.f is not set.
OS: Linux → All
Hardware: x86 → All
Can you explain a bit whats happening here and why undefined is the expected outcome?
Sure.  From top to bottom:

We want ctors exposed by Jetpack APIs to be callable with or without the `new` operator.  makePublicCtor takes a "private" ctor and returns a function PublicCtor that may be used as a ctor or may be called as a normal function.  PublicCtor creates objects that are instances of both the private ctor and PublicCtor itself.  In my test case, makePublicCtor is defined in a sandbox because in Jetpack all modules are sandboxed, including the module that exports this makePublicCtor function.

The ensure function takes an object and replaces one of its methods.  The replacement method takes advantage of the closure to maintain a flag to determine whether it has been called more than once.  So the first time the replacement method is called, the flag is unset, so the method does its business and sets the flag.  When the method is subsequently called, it sees that the flag has been set and returns early.  My test case simplifies the replacement method so that it simply sets the flag to "foo" after storing the flag's current value.  The first time the method is called, x should not be set, so curr_x should be undefined.  For subsequent calls of the same method, curr_x should be "foo".

The rest of the test case sets up private and public ctors and creates two different objects.  ensure(this) is called in the private ctor to replace method f on the new object.  So the new object hasOwnProperty("f") while also having f in its prototype chain.

`o1 = Public()` calls an instance of PublicCtor, which applies Private to the new object, which calls ensure on the new object, creating a new closure involving x and the object.  `o2 = Public()` does the same.  But it's as if o2.f() uses the same closure that was used for o1.f(), since x has apparently already been set to "foo".  Which implies that o1.f and o2.f might be the same function.

Actually, that appears to be what's happening:

  var sp = Components.classes["@mozilla.org/systemprincipal;1"].
           createInstance(Components.interfaces.nsIPrincipal);
  var s = Components.utils.Sandbox(sp);
  Components.utils.evalInSandbox(
    'function makePublicCtor(privateCtor) {' +
    '  function PublicCtor() {' +
    '    var obj = { __proto__: PublicCtor.prototype };' +
    '    privateCtor.apply(obj, arguments);' +
    '    return obj;' +
    '  }' +
    '  PublicCtor.prototype = { __proto__: privateCtor.prototype };' +
    '  return PublicCtor;' +
    '}',
    s
  );
  function Private() this.f = function () {};
  Private.prototype = { f: function () {} };
  var Public = s.makePublicCtor(Private);
  var o1 = Public();
  var o2 = Public();
  o1.f == o2.f; /* true */

But `Public().f == Public().f` is false.  Weird.
This might be a deep-wrapping issue (lack there of). I am still a bit confused by what the code is trying to do here.
Blocks a blocker. Please b7+.
Component: Jetpack SDK → XPConnect
Product: Mozilla Labs → Core
QA Contact: jetpack-sdk → xpconnect
Target Milestone: -- → mozilla2.0b7
Version: unspecified → Trunk
blocking2.0: --- → ?
I explained everything pretty clearly.  What do you want to know by asking what it's trying to do?
blocking2.0: ? → beta7+
#14 and #15 collided. I am stepping through the code again with your explanation.
Drew, I am sorry, I am still confused here. What values do you expect to get, and what values are you seeing. Do the comments show what you see, or what you want to see?
gal@alien:~/workspace/jetpack-sdk/packages/jetpack-core$ ../../bin/cfx test -F tab-browser --binary=~/workspace/tracemonkey-repository/debug-build/dist/bin/firefox 2>&1 | sed -n -e '/OK/p' -e '/FAIL/p' -e '/tests/p' 
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 56, in 
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 211, in 
error: TEST FAILED: test-tab-browser.testTrackerWithoutDelegate (timed out)
27 of 28 tests passed.
FAIL

This is what I get from the harness.
For the record, in your test cases above I get undefined for the first for both, and the 2nd neither o1/o2 nor Public.f/Public.f are identical.
JavaScript strict warning: resource://jetpack-core-jetpack-core-lib/securable-module.js -> resource://jetpack-core-jetpack-core-lib/securable-module.js -> resource://jetpack-core-jetpack-core-lib/tab-browser.js, line 203: reference to undefined property this._browsers
error: An exception occurred.
Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/timer.js", line 64, in notifyOnTimeout
    this._callback.apply(null, this._params);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 56, in 
    callback(window, browsers[0]);
  File "resource://jetpack-core-jetpack-core-tests/test-tab-browser.js", line 216, in 
    if (tb.length == 0)
  File "resource://jetpack-core-jetpack-core-lib/tab-browser.js", line 203, in 
    return this._browsers.length;
TypeError: this._browsers is undefined
console: [JavaScript Warning: "reference to undefined property this._browsers" {file: "resource://jetpack-core-jetpack-core-lib/securable-module.js -> resource://jetpack-core-jetpack-core-lib/securable-module.js -> resource://jetpack-core-jetpack-core-lib/tab-browser.js" line: 203}]

We throw an exception pretty early on on the testTrackerWithoutDelegate test because _browsers is not defined.
Not eager to own this but someone should. Anyone please feel free to steal. Otherwise I am waiting for Blake's obj/obj2 patch to land and I am praying that one fixes this or we get a reduced version (I can't even attach with gdb to this with the cfx harness).
Assignee: nobody → gal
I've posted two reduced versions now.  The comments show what I see with a build that includes the mozilla-central tip from last night and Blake's patch in bug 596031.  Without Blake's patch, I get the "_browsers is undefined" error.  Ergo Blake's patch fixes one prototype-related bug but either introduces or reveals another one.  My two reduced cases show that two different objects which should have two different methods f apparently have the same method f.  They should not have the same method f.  The expected behavior for the two test cases is what your comment 21 says.

I can't reduce the test case anymore than what's in comment 14.
Thanks for the clarification drew. It looks to me the next nightly will fix your test case then and we are back to the _browsers issue. We still have an outstanding patch from blake. I will check tomorrow how we are doing with that. I didn't make progress with diagnosing the _browsers issue.
Thanks Andreas, but I'm not following -- the most current nightly produces the "_browsers is undefined" error.  We (at least I, but maybe Blake too) thought that his obj/obj2 patch in bug 596031 would fix that.  It does, but it either introduces or reveals another bug, which is the source of this "item is null" error that I've been tracking since comment 10 and is what my two test cases show.

So, two problems: first was _browsers, which Blake's obj/obj2 patch fixed, second and current one is what my test cases are trying to show.
Ok, I see. We need Blake's patch landed and then we will re-test with your test cases.
This is fixed when running with mrbkap's fixes for bug 596031 and bug 607767 (newer patch than what's in the bug).
I am marking this fixed based on #28.
Status: NEW → RESOLVED
Closed: 14 years ago
Resolution: --- → FIXED
(In reply to comment #29)
> I am marking this fixed based on #28.

Shouldn't we wait to do that until those fixes actually land?
You need to log in before you can comment on or make changes to this bug.