645241 - Fix frame handling of assertions to report the test function and not a module as top frame

Reporter

Description

•

13 years ago

At the moment when you execute the tests for the new assertions module you will see that the top frame is still not accurate. The failure is reported in the assertion module itself and not in the test:

Step Pass: {"pass": {"function": "Expect__test", "message": " (AssertionError). assert.equal for [true, false, true is not equal to false]", "lineNumber": 113, "fileName": "resource://mozmill/modules/assertions.js"}}

That's exactly what I have changed with my stack walker in our own module. That's kinda important.

Henrik Skupin [:whimboo][⌚️UTC+1]

Reporter

Comment 1

•

13 years ago

The output we currently have in our own assertion module is:

INFO | Step Pass: {"pass": {"function": "testAssert", "message": "assert.equal for [true, false, true is not equal to false]", "lineNumber": 132, "fileName": "file:///Volumes/data/testing/mozmill/api-refactor/modules/tests/test_assertions.js"}}

cmtalbert

Assignee

Comment 2

•

13 years ago

Looks like this is already solved in mochitest, we should check out simpletest.js to see how they do it.

Whiteboard: [mozmill-2.0?] → [mozmill-2.0+]

Heather Arthur [:harth]

Updated

•

13 years ago

Assignee: nobody → fayearthur+bugs

Heather Arthur [:harth]

Updated

•

13 years ago

Status: NEW → ASSIGNED

cmtalbert

Assignee

Comment 3

•

13 years ago

(In reply to comment #2)
> Looks like this is already solved in mochitest, we should check out
> simpletest.js to see how they do it.

So, this isn't done in mochitest.  Mochitest doesn't report stacks.  Because we are truly reporting stacks we are bound by what is on the stack.  Since you'll always have the data you need in the stack, you only have one extra function on the stack.  So, let's just move on and focus on more import issues.

recommending WONTFIX

Status: ASSIGNED → RESOLVED

Closed: 13 years ago

Resolution: --- → WONTFIX

Henrik Skupin [:whimboo][⌚️UTC+1]

Reporter

Comment 4

•

13 years ago

I have to reopen this bug because the current situation is not satisfying. Any info or error message you get will report a pass/fail in assertions.js but not at the exact place of the test or module:

INFO | Step Pass: {"function": "controller.waitForPageLoad()"}
ERROR | Test Failure: {"fail": {"function": "Expect__test", "message": "Element 'hplog' has been found. - got 'false'", "lineNumber": 113, "fileName": "resource://mozmill/modules/assertions.js"}}
INFO | Step Pass: {"function": "Controller.open()"}
INFO | Step Pass: {"function": "controller.waitFor()"}
INFO | Step Pass: {"function": "controller.waitForPageLoad()"}
INFO | Step Pass: {"pass": {"function": "Expect__test", "message": "Element 'search-q' has been found. - got 'true'", "lineNumber": 113, "fileName": "resource://mozmill/modules/assertions.js"}}
INFO | Step Pass: {"function": "Controller.open()"}
INFO | Step Pass: {"function": "controller.waitFor()"}
INFO | Step Pass: {"function": "controller.waitForPageLoad()"}
INFO | Step Pass: {"pass": {"function": "Expect__test", "message": "Element 'firefox' has been found. - got 'true'", "lineNumber": 113, "fileName": "resource://mozmill/modules/assertions.js"}}

That's absolutely not helpful for debugging and works fine in our API rewrite.

Status: RESOLVED → REOPENED

Resolution: WONTFIX → ---

cmtalbert

Assignee

Comment 5

•

13 years ago

I'm going to look into this as I said in the mozmill meeting.  Probably look at it early next week sept 26 or so...

Assignee: fayearthur+bugs → ctalbert

cmtalbert

Assignee

Comment 6

•

13 years ago

Attached patch wip (obsolete) — Details — Splinter Review

So, this is the direction I'm thinking of going.  There is a lot of code in here, and a lot of it is still debugging because I'm still working through everything.  Here are the changes:

* pprint didn't output any stacks, ever.  The if statement in pprint was wrong and group(3) was always None.  fixed that
* added a little test that blows up so I can see what stacks we are reporting
* added my usual file log debugging cause I can't live without it (going to remove)
* added in Henrik's code from api-refactor for stack munging.

And here is the big change:
It reports the file name, message, and linenumber of the failure in the test file that called into assertions.js.  I think this is the most important part of what Henrik wanted.  I tried using the stripStackInformation funciton as well, but it made a royal mess of the stack and I couldn't make heads or tails of what I was looking at afterward.

So, my compromise is thus: we report the test file, filename, and message from the file under test, but for the stack variable, we report the full JS stack in normal JSON, with all it's information.  I think this gives us the best of both worlds, and since we can depend on the JS stack format not really changing, we can change our tools to properly show format it so that it's not the ugly beast it looks like below.  (This means I'll be changing pprint in logger.py to properly format it).

Here's an example of what this all looks like (not pretty printed, obviously):

(mozmill2.0)ctalbert@mozilla-ThinkPad-X201s:~/projects/mozmill$ mozmill -b ~/tools/nightly/firefox -t mutt/mutt/tests/js/test_expectstack.js
TEST-START | mutt/mutt/tests/js/test_expectstack.js | setupModule
TEST-START | mutt/mutt/tests/js/test_expectstack.js | testExpectStack
INFO | Step Pass: {"function": "Controller.open()"}
ERROR | Test Failure: {"fail": {"function": "Expect__test", "message": "Element foobar_the_friendly has been found. - got 'false'", "lineNumber": 13, "stack": {"caller": {"caller": {"caller": {"caller": {"caller": {"caller": {"caller": {"caller": {"caller": {"caller": {"caller": {"caller": null, "name": null, "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://jsbridge/modules/nspr-server.js", "lineNumber": 59}, "name": null, "language": 1, "sourceLine": null, "languageName": "C++", "filename": null, "lineNumber": 0}, "name": null, "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://jsbridge/modules/bridge.js", "lineNumber": 139}, "name": null, "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://jsbridge/modules/bridge.js", "lineNumber": 135}, "name": null, "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://mozmill/modules/frame.js", "lineNumber": 568}, "name": null, "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://mozmill/modules/frame.js", "lineNumber": 465}, "name": null, "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://mozmill/modules/frame.js", "lineNumber": 542}, "name": null, "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://mozmill/modules/frame.js", "lineNumber": 497}, "name": null, "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://mozmill/modules/frame.js -> file:///home/ctalbert/projects/mozmill/mutt/mutt/tests/js/test_expectstack.js", "lineNumber": 13}, "name": null, "language": 1, "sourceLine": null, "languageName": "C++", "filename": null, "lineNumber": 0}, "name": "Expect_ok", "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://mozmill/stdlib/securable-module.js -> resource://mozmill/modules/assertions.js", "lineNumber": 180}, "name": "Expect__test", "language": 2, "sourceLine": null, "languageName": "JavaScript", "filename": "resource://mozmill/stdlib/securable-module.js -> resource://mozmill/modules/assertions.js", "lineNumber": 133}, "fileName": "file:///home/ctalbert/projects/mozmill/mutt/mutt/tests/js/test_expectstack.js"}}
TEST-UNEXPECTED-FAIL | mutt/mutt/tests/js/test_expectstack.js | testExpectStack
INFO | Passed: 0
INFO | Failed: 1
INFO | Skipped: 0

What do y'all think?

Attachment #563619 - Flags: feedback?(jhammel)

cmtalbert

Assignee

Updated

•

13 years ago

Status: REOPENED → ASSIGNED

Jeff Hammel

Comment 7

•

13 years ago

Comment on attachment 563619 [details] [diff] [review]
wip

Looks great to me!

IMHO you might as well check in filelog.js.  We're going to need to fix our debugging story at some point, but i don't see any reason not to include the file now. (Obviously not the places you utilize it.)

Attachment #563619 - Flags: feedback?(jhammel) → feedback+

cmtalbert

Assignee

Comment 8

•

13 years ago

Attached patch a final-ish patch (obsolete) — Details — Splinter Review

Ok, here's a final.  This is the output now:

(mozmill2.0)ctalbert@mozilla-ThinkPad-X201s:~/projects/mozmill$ mozmill -b ~/tools/nightly/firefox -t mutt/mutt/tests/js/test_expectstack.js --format=pprint-color
TEST-START | mutt/mutt/tests/js/test_expectstack.js | setupModule
TEST-START | mutt/mutt/tests/js/test_expectstack.js | testExpectStack
INFO | Step Pass: {
  "function": "Controller.open()"
}
ERROR | Test Failure: {
  "fail": {
    "function": "Expect__test", 
    "message": "Element foobar_the_friendly has been found. - got 'false'", 
    "lineNumber": 13, 
    "stack": {
      "filename": "resource://mozmill/stdlib/securable-module.js -> resource://mozmill/modules/assertions.js", 
      "languageName": "JavaScript", 
      "name": "Expect__test", 
      "caller": {
        "filename": "resource://mozmill/stdlib/securable-module.js -> resource://mozmill/modules/assertions.js", 
        "languageName": "JavaScript", 
        "name": "Expect_ok", 
        "caller": {
          "caller": {
            "caller": {
              "caller": {
                "caller": {
                  "caller": {
                    "caller": {
                      "caller": {
                        "caller": {
                          "caller": {
                            "languageName": "JavaScript", 
                            "filename": "resource://jsbridge/modules/nspr-server.js", 
                            "lineNumber": 59
                          }, 
                          "languageName": "C++", 
                          "filename": null, 
                          "lineNumber": 0
                        }, 
                        "languageName": "JavaScript", 
                        "filename": "resource://jsbridge/modules/bridge.js", 
                        "lineNumber": 139
                      }, 
                      "languageName": "JavaScript", 
                      "filename": "resource://jsbridge/modules/bridge.js", 
                      "lineNumber": 135
                    }, 
                    "languageName": "JavaScript", 
                    "filename": "resource://mozmill/modules/frame.js", 
                    "lineNumber": 568
                  }, 
                  "languageName": "JavaScript", 
                  "filename": "resource://mozmill/modules/frame.js", 
                  "lineNumber": 465
                }, 
                "languageName": "JavaScript", 
                "filename": "resource://mozmill/modules/frame.js", 
                "lineNumber": 542
              }, 
              "languageName": "JavaScript", 
              "filename": "resource://mozmill/modules/frame.js", 
              "lineNumber": 497
            }, 
            "languageName": "JavaScript", 
            "filename": "resource://mozmill/modules/frame.js -> file:///home/ctalbert/projects/mozmill/mutt/mutt/tests/js/test_expectstack.js", 
            "lineNumber": 13
          }, 
          "languageName": "C++", 
          "filename": null, 
          "lineNumber": 0
        }, 
        "lineNumber": 168
      }, 
      "lineNumber": 121
    }, 
    "fileName": "file:///home/ctalbert/projects/mozmill/mutt/mutt/tests/js/test_expectstack.js"
  }
}
TEST-UNEXPECTED-FAIL | mutt/mutt/tests/js/test_expectstack.js | testExpectStack
INFO | Passed: 0
INFO | Failed: 1
INFO | Skipped: 0

Attachment #563619 - Attachment is obsolete: true

Attachment #563877 - Flags: review?(jhammel)

Jeff Hammel

Comment 9

•

13 years ago

Comment on attachment 563877 [details] [diff] [review]
a final-ish patch

Looks great :) I assume this works with the existing mutt tests?

Attachment #563877 - Flags: review?(jhammel) → review+

cmtalbert

Assignee

Comment 10

•

13 years ago

Attached patch Final patch with test — Details — Splinter Review

Same patch, with test

Attachment #563877 - Attachment is obsolete: true

Attachment #564394 - Flags: review?(jhammel)

Jeff Hammel

Comment 11

•

13 years ago

Comment on attachment 564394 [details] [diff] [review]
Final patch with test

Looks good.

Traditionally the pattern is for python test that need JS resources to put the test in the tests/python directory, but as it stands is probably fine

Attachment #564394 - Flags: review?(jhammel) → review+

cmtalbert

Assignee

Comment 12

•

13 years ago

(In reply to Jeff Hammel [:jhammel] from comment #11)
> Comment on attachment 564394 [details] [diff] [review] [diff] [details] [review]
> Final patch with test
> 
> Looks good.
> 
> Traditionally the pattern is for python test that need JS resources to put
> the test in the tests/python directory, but as it stands is probably fine

Oh currently all the tests I was aware of reference the javascript tests out of the js/ subdirectory.  We could start pulling those over into the python/ directory I suppose.  

Anyhow, left as is for the moment and landed: https://github.com/mozautomation/mozmill/commit/0bb9d541549e54bf0754dde982fa824d6f6242a0

Status: ASSIGNED → RESOLVED

Closed: 13 years ago → 13 years ago

Resolution: --- → FIXED

Jeff Hammel

Comment 13

•

13 years ago

Sorry I thought there were some there but indeed you are right.  My mistake.

Henrik Skupin [:whimboo][⌚️UTC+1]

Reporter

Comment 15

•

13 years ago

Looks good. Thanks Clint for this patch. It makes it a way better to understand failures.

Status: RESOLVED → VERIFIED

Nobody; OK to take it and work on it

Updated

•

8 years ago

Product: Testing → Testing Graveyard

wip 13 years ago cmtalbert 8.99 KB, patch	k0scist : feedback+	Details \| Diff \| Splinter Review
a final-ish patch 13 years ago cmtalbert 8.47 KB, patch	k0scist : review+	Details \| Diff \| Splinter Review
Final patch with test 13 years ago cmtalbert 11.11 KB, patch	k0scist : review+	Details \| Diff \| Splinter Review