Open Bug 613023 Opened 9 years ago Updated 11 months ago

Add line numbers to the log messages generated by the browser chrome harness

Categories

(Testing :: Mochitest, defect)

defect
Not set

Tracking

(Not tracked)

People

(Reporter: mossop, Unassigned)

Details

(Whiteboard: [has patch])

Attachments

(1 file, 3 obsolete files)

Makes it easy to find the exact point in the file that generated it even when the same message is logged multiple times.
Attached patch patch rev 1 (obsolete) — Splinter Review
This includes the exact file and line with each logged message, it is either the line that called the logging function or it is the line that generated the exception passed to the logging function.

One downside here is that sometimes the file is not the main test file, can be in the head file or anything else included f.e. This could make it harder to identify the exact test that was running from the tinderbox summary.

Another potential problem is that this might break anything that tries to parse our log files (brasstacks f.e.).
Assignee: nobody → dtownsend
Status: NEW → ASSIGNED
Attachment #491318 - Flags: review?(gavin.sharp)
Attached file example log (obsolete) —
This is an example of what is generated
Attachment #491321 - Attachment mime type: application/octet-stream → text/plain
Whiteboard: [has patch][needs review gavin]
Comment on attachment 491318 [details] [diff] [review]
patch rev 1

I think we shouldn't switch away from using this.path, it's going to confuse too many people. Perhaps we should only include this information for failing tests, on a separate line?
Attachment #491318 - Flags: review?(gavin.sharp) → review-
Attached patch patch rev 2 (obsolete) — Splinter Review
So something like this. Not sure about the output, currently it is like this:

TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/browser_list.js | Name should be correct - Got Test add-on, expected Tesst add-on
AT chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/browser_list.js:131

I presume that starting the second line with TEST-UNEXPECTED-FAIL would lead to over-counting fails so I went with something different. I guess with a but of work it is probably possible to get a full stack for the failures too.
Attachment #491318 - Attachment is obsolete: true
Attachment #491321 - Attachment is obsolete: true
Attachment #531790 - Flags: review?(gavin.sharp)
Comment on attachment 531790 [details] [diff] [review]
patch rev 2

>diff --git a/testing/mochitest/browser-harness.xul b/testing/mochitest/browser-harness.xul

>       addResult: function addResult(result) {

>+        if (!result.info && !result.pass)
>+          this.dumper.dump("AT " + result.fileName + ":" + result.lineNumber + "\n");

maybe prefix with a \t?

>diff --git a/testing/mochitest/browser-test.js b/testing/mochitest/browser-test.js

>+  if (aDiag && typeof aDiag == "object" && "fileName" in aDiag) {
>+    // we have an exception use it for filename and linenumber information
>+    this.fileName = aDiag.fileName;
>+    this.lineNumber = aDiag.lineNumber;
>+  }
>+  else {
>+    var frame = Components.stack.caller.caller.caller;
>+    this.fileName = frame.filename;
>+    this.lineNumber = frame.lineNumber;
>+  }

I wonder whether we should bother with the special handling of aDiag - it's a bit odd to use a different source for the lineNumber/fileName only for certain cases, particularly since that information from the exception should be printed in its toString (which is appended to this.msg). I'm not sure in which cases exactly they would differ.

> function testMessage(aName) {

>+  var frame = Components.stack.caller.caller;
>+  this.fileName = frame.filename;
>+  this.lineNumber = frame.lineNumber;

Not sure this is useful given that they're never used (this.info is true), but I suppose it doesn't hurt.

>diff --git a/toolkit/mozapps/extensions/test/browser/browser_list.js b/toolkit/mozapps/extensions/test/browser/browser_list.js

Doesn't look related to this patch :)
Attachment #531790 - Flags: review?(gavin.sharp) → review+
(In reply to comment #5)
> >diff --git a/toolkit/mozapps/extensions/test/browser/browser_list.js b/toolkit/mozapps/extensions/test/browser/browser_list.js
> 
> Doesn't look related to this patch :)

Oh I see, you were using it to tesst!
(In reply to comment #5)
> >diff --git a/testing/mochitest/browser-test.js b/testing/mochitest/browser-test.js
> 
> >+  if (aDiag && typeof aDiag == "object" && "fileName" in aDiag) {
> >+    // we have an exception use it for filename and linenumber information
> >+    this.fileName = aDiag.fileName;
> >+    this.lineNumber = aDiag.lineNumber;
> >+  }
> >+  else {
> >+    var frame = Components.stack.caller.caller.caller;
> >+    this.fileName = frame.filename;
> >+    this.lineNumber = frame.lineNumber;
> >+  }
> 
> I wonder whether we should bother with the special handling of aDiag - it's
> a bit odd to use a different source for the lineNumber/fileName only for
> certain cases, particularly since that information from the exception should
> be printed in its toString (which is appended to this.msg). I'm not sure in
> which cases exactly they would differ.

They'll differ because the exception can be thrown from a different link to that that adds the test result (see the exception catching from running the test f.e.). The exception line is likely more interesting.
Attached patch patch rev 3Splinter Review
Wanted to quickly confirm you're ok with what I said above, also added printing of exceptions from executeSoon callbacks here
Attachment #531790 - Attachment is obsolete: true
Attachment #532056 - Flags: review?(gavin.sharp)
Comment on attachment 532056 [details] [diff] [review]
patch rev 3

(In reply to comment #7)
> The exception line is likely more interesting.

Right, but the exception line shows up either way, since we print the exception entirely, right? It just seems odd to have the source of the actual line number differ in the case where there's an exception. But that's probably fine I guess.

>diff --git a/testing/mochitest/browser-test.js b/testing/mochitest/browser-test.js

>   this.executeSoon = function test_executeSoon(func) {
>     let tm = Cc["@mozilla.org/thread-manager;1"].getService(Ci.nsIThreadManager);
> 
>     tm.mainThread.dispatch({
>       run: function() {
>+        try {
>+          func();
>+        } catch (ex) {
>+          self.__brwoserTest.addResult(new testResult(false, "Exception thrown",
>+                                                      ex, false));

This isn't going to work until the brwoser-chrome harness is up and running. Also I don't think "self" is defined here.
Attachment #532056 - Flags: review?(gavin.sharp) → review-
Whiteboard: [has patch][needs review gavin] → [has patch]
Assignee: dtownsend → nobody
Component: BrowserTest → Mochitest
No assignee, updating the status.
Status: ASSIGNED → NEW
No assignee, updating the status.
You need to log in before you can comment on or make changes to this bug.