browser-harness.xul: issues with deferred log generation

VERIFIED FIXED in mozilla1.9.2a1

Status

defect
--
major
VERIFIED FIXED
10 years ago
2 years ago

People

(Reporter: sgautherie, Assigned: Gavin)

Tracking

({autotest-issue, fixed1.9.1})

Trunk
mozilla1.9.2a1
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [fixed1.9.1rc2], )

Attachments

(1 attachment, 2 obsolete attachments)

{
251     function getHTMLLogFromTests(aTests) {

272     function getLogFromTests(aTests) {
}
are called and generate the tests log(s) at the end of the suite run.

This has some issues:
*No way to tell which test is currently running.
*"Tests outputs" are all logged before these functions are called,
 making them "near useless" as they are out of sync'.
*In case of a crash (or manual browser exit), these functions are not called,
 and we get no log.

See
{
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1242074648.1242081648.31736.gz&fulltext=1
Linux mozilla-central unit test on 2009/05/11 13:44:08

[...]
About to focus the tagsField

command timed out: 1200 seconds without output, killing pid 8408
process killed by signal 9
program finished with exit code -1
}
as an example of the latter:
makes it impossible to find out what happened :-(
Summary: browser-harness.xul issues with log handling → browser-harness.xul: issues with deferred log generation
Note to self:
I would also want to use a todo()/ok() on |f.log|,
+/- as I'm proposing in bug 483407 for SimpleTest.js.
Blocks: 483407
Duplicate of this bug: 495091
bug 493355 is another case where this would be really useful. and probably also Mossop's patch in bug 481406.
Posted patch patch (obsolete) — Splinter Review
This flushes the log to both stdout and the logfile after each test completes. It would be possible to have it output each subtest result as they are generated, but that's slightly more complicated, so I figure this is a good first step. We do dump the test path before starting the test, so you can still identify tests that cause crashes/hangs.
Assignee: nobody → gavin.sharp
Status: NEW → ASSIGNED
Attachment #382001 - Flags: review?(dtownsend)
Attachment #382001 - Attachment is obsolete: true
Attachment #382001 - Flags: review?(dtownsend)
Posted patch patch v2 (obsolete) — Splinter Review
This patch implements per-result dumping. Tests have a reference to the Dumper object, and call it whenever a result is added. The Tester still takes care of the summary and "Running..." output, and the in-UI HTML display is still just generated from the tests array as before.
Attachment #382013 - Flags: review?(dtownsend)
Blocks: 493355
Comment on attachment 382013 [details] [diff] [review]
patch v2

Few little bits to clean up I think.

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

>+    var gDumper = {
>+      get fileLogger() {
>+        let logger = null;
>+        if (gConfig.logPath) {
>+          try {
>+            MozillaFileLogger.init(gConfig.logPath);
>+            logger = MozillaFileLogger;
>+          } catch (ex) {
>+            dump("TEST-UNEXPECTED-FAIL | (browser-harness.xul) | " +
>+                 "Error trying to log to " + gConfig.logPath + ": " + ex + "\n");
>+          }

This is going to infinitely recurse if MozillaFileLogger.init throws. Just delete fileLogger at the start I think.

>-    function browserTestFile(aTestFile) {
>+    function browserTest(aTestFile, aDumper) {

Is there a need to pass in the dumper when it is always gDumper?

>     // Returns an array of chrome:// URLs to all the test files
>     function listTests() {

Can you just fix this comment to match reality while you're here. Something like "Returns an array of browserTest objects for all the selected tests".

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

>   start: function Tester_start() {
>+    this.dumper.dump("*** Start BrowserChrome Test Results ***\n");
>+
>     if (this.tests.length)
>       this.execTest();
>-    else
>-      this.finish();
>+    else {
>+      this.dumper.dump("TEST-UNEXPECTED-FAIL | (browser-test.js) | " +
>+                       "No tests to run. Did you pass an invalid --test-path?");
>+      this.finish(true);
>+    }
>   },
> 
>-  finish: function Tester_finish() {
>+  finish: function Tester_finish(aSkipSummary) {
>+    if (!aSkipSummary) {
>+      this.dumper.dump("\nBrowser Chrome Test Summary\n");
>+  
>+      function sum(a,b) a+b;
>+      var passCount = this.tests.map(function (f) f.passCount).reduce(sum);
>+      var failCount = this.tests.map(function (f) f.failCount).reduce(sum);
>+      var todoCount = this.tests.map(function (f) f.todoCount).reduce(sum);
>+  
>+      this.dumper.dump("\tPass: " + passCount + "\n\tFail: " + failCount + "\n\tTodo: " + todoCount + "\n");  
>+    }
>+
>+    this.dumper.dump("\n*** End BrowserChrome Test Results ***\n");
>+
>+    this.dumper.done();
>+
>     // Tests complete, notify the callback and return
>     this.callback(this.tests);
>     this.callback = null;
>     this.tests = null;
>   },

I don't really see the point in aSkipSummary. You can just check this.tests.length there and either display the summary or the error directly.
Attachment #382013 - Flags: review?(dtownsend) → review-
The MozillaFileLogger.init thing is OK since we're calling dump(), not this.dump().
Attachment #382013 - Attachment is obsolete: true
Attachment #382121 - Flags: review?(dtownsend)
Comment on attachment 382121 [details] [diff] [review]
comments addressed
[Checkin: Comment 9 & 10]

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

>   start: function Tester_start() {
>+    this.dumper.dump("*** Start BrowserChrome Test Results ***\n");
>+
>     if (this.tests.length)
>       this.execTest();
>-    else
>+    else {
>       this.finish();
>+    }
>   },

Nit: don't need to add the braces anymore.
Attachment #382121 - Flags: review?(dtownsend) → review+
Comment on attachment 382121 [details] [diff] [review]
comments addressed
[Checkin: Comment 9 & 10]


http://hg.mozilla.org/mozilla-central/rev/1526cbec0c7d
with comment 8 suggestion(s).
Attachment #382121 - Attachment description: comments addressed → comments addressed [Checkin: Comment 9]
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Whiteboard: [needs 1.9.1 landing]
Target Milestone: --- → mozilla1.9.2a1
Comment on attachment 382121 [details] [diff] [review]
comments addressed
[Checkin: Comment 9 & 10]


http://hg.mozilla.org/releases/mozilla-1.9.1/rev/4f00c763a32d
Attachment #382121 - Attachment description: comments addressed [Checkin: Comment 9] → comments addressed [Checkin: Comment 9 & 10]
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1244821212.1244828233.27553.gz&fulltext=1
WINNT 5.2 mozilla-central unit test on 2009/06/12 08:40:12

V.Fixed
Status: RESOLVED → VERIFIED
Whiteboard: [needs 1.9.1 landing] → [fixed1.9.1rc1+]
Blocks: 496058
Whiteboard: [fixed1.9.1rc1+] → [fixed1.9.1rc2]
Component: BrowserTest → Mochitest
You need to log in before you can comment on or make changes to this bug.