596818 - test runner only reports test function for first test failure

Status: RESOLVED FIXED

(Add-on SDK Graveyard :: General, defect)

Description

[Myk Melez [:myk] [@mykmelez]]

When tests in multiple test functions fail, the test runner only reports the function for the first test that failed.

It reports the failures themselves, including expected/actual values and tracebacks.  And it's possible to figure out the test function for a failure by finding the entry for the test file in the traceback, opening the file, finding the line on which the failure occurred, and figuring out what function contains that line.

But that's quite painful.  We shouldn't subject developers to such pain.  So the test runner should report the function and file for each test failure.

To illustrate the problem, here's an example in which four tests fail, two in test-page-mod.js and two in test-traceback.js (my comments in square brackets):


(jsdk)myk@myk:~/Projects/jsdk/packages/jetpack-core$ cfx test -a firefox -b ~/Applications/firefox-trunk/firefox -F 'page-mod|traceback'
Using binary at '/home/myk/Applications/firefox-trunk/firefox'.
Using profile at '/tmp/tmp0rbp5f.mozrunner'.

(firefox-bin:27644): GLib-WARNING **: g_set_prgname() called multiple times
.......error: TEST FAILED: test-page-mod.testPageModIncludes (failure)
error: fail: 'about:*' match test, expected: true
info: Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-tests/pagemod-test-helpers.js", line 41, in onPageLoad
    testCallback(b.contentWindow.wrappedJSObject, function done() {
  File "resource://jetpack-core-jetpack-core-tests/test-page-mod.js", line 95, in anonymous
    asserts.forEach(function(fn) {
  File "resource://jetpack-core-jetpack-core-tests/test-page-mod.js", line 96, in anonymous
    fn(test, win);
  File "resource://jetpack-core-jetpack-core-tests/test-page-mod.js", line 71, in anonymous
    "'" + include + "' match test, expected: " + expectedMatch);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 196, in assert
    this.fail(message);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 145, in fail
    console.trace();

[For this first test failure, the runner reports the file, test-page-mod.js, and the function, testPageModIncludes(), in which the test failed.]


.error: fail: 'about:buildconfig' match test, expected: true
info: Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-tests/pagemod-test-helpers.js", line 41, in onPageLoad
    testCallback(b.contentWindow.wrappedJSObject, function done() {
  File "resource://jetpack-core-jetpack-core-tests/test-page-mod.js", line 95, in anonymous
    asserts.forEach(function(fn) {
  File "resource://jetpack-core-jetpack-core-tests/test-page-mod.js", line 96, in anonymous
    fn(test, win);
  File "resource://jetpack-core-jetpack-core-tests/test-page-mod.js", line 71, in anonymous
    "'" + include + "' match test, expected: " + expectedMatch);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 196, in assert
    this.fail(message);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 145, in fail
    console.trace();

[For this test failure, the runner doesn't specify the function, so we have to read the traceback to determine that the failure is on line 71 of test-page-mod.js.  And then we have to read the traceback to determine that the failure is also in the testPageModIncludes() test function.]


...........................error: fail: "throwError" != "Error"
info: Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/timer.js", line 60, in notify
    this._callback.apply(null, this._params);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 255, in anonymous
    timer.setTimeout(function() { onDone(self); }, 0);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 280, in runNextTest
    self.start({test: test, onDone: runNextTest});
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 298, in start
    this.test.testFunction(this);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 63, in runTest
    test(runner);
  File "resource://jetpack-core-jetpack-core-tests/test-traceback.js", line 66, in anonymous
    "Error");
  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();

[This failure is in a different test function, testFromExceptionWithError(), in a completely different test file, test-traceback.js, although you wouldn't know it without reading through the traceback and then opening the test file.]


error: fail: "" != "throwError"
info: Traceback (most recent call last):
  File "resource://jetpack-core-jetpack-core-lib/timer.js", line 60, in notify
    this._callback.apply(null, this._params);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 255, in anonymous
    timer.setTimeout(function() { onDone(self); }, 0);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 280, in runNextTest
    self.start({test: test, onDone: runNextTest});
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 298, in start
    this.test.testFunction(this);
  File "resource://jetpack-core-jetpack-core-lib/unit-test.js", line 63, in runTest
    test(runner);
  File "resource://jetpack-core-jetpack-core-tests/test-traceback.js", line 68, in anonymous
    "throwError");
  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();

[This test failure happens to be in the same test function as the previous one.  Again, one must read the traceback and test file to determine that.]

Comment 1

[Myk Melez [:myk] [@mykmelez]]

The Add-on SDK is no longer a Mozilla Labs experiment and has become a big enough project to warrant its own Bugzilla product, so the "Add-on SDK" product has been created for it, and I am moving its bugs to that product.

To filter bugmail related to this change, filter on the word "looptid".

Comment 2

[Irakli Gozalishvili [:irakli] [:gozala] [@gozala]]

Attachment: Pointer to pull request

Comment 3

[Myk Melez [:myk] [@mykmelez]]

Comment on attachment 518343 [details]
Pointer to pull request

Quis custodiet ipsos custodes?

Comment 4

[Irakli Gozalishvili [:irakli] [:gozala] [@gozala]]

Myk, I did not managed to translate your comment, but I pushed the change as it had r+

Comment 5

[Myk Melez [:myk] [@mykmelez]]

No worries, it was just a way of wondering how we might test changes to the test harness itself.