Closed Bug 379327 Opened 13 years ago Closed 12 years ago

make tinderbox logs suck less when tests fail

Categories

(Testing :: Mochitest, defect)

x86
macOS
defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: sayrer, Assigned: ted)

References

Details

Attachments

(5 files)

so, our testing infrastructure is finding errors pretty well. most people don't realize that though, because the tinderbox log makes a mess of things, ignorantly grepping for things that look like compile errors.

we need to:

1) stop reporting errors that aren't errors in the summary
2) make exit codes clear
3) make test failures clear
4) make it clear which file a failure occured in, where possible
I filed this as bug 374642 when we had talked about it last.
Duplicate of this bug: 374642
Duplicate of this bug: 378040

comments from duped bug 378040 filed by Ted:

When a test fails on the unit test box, you usually have to search through the
full log to find what failed.  In addition, you have to look for different
things for each type of test: "UNEXPECTED " for reftest and "ERROR FAIL" for
mochitest and chrome, and for TUnit, look for stacks.

It would be awesome if Tinderbox could parse out the failures and show them in
the brief log, or something like that.

Comment #1 [reply] cls  2007-04-25 12:10:14 PDT

It sounds as though the tests need to be modified to return a standard format
for the error condition.  In webtools/tinderbox/ep_unix.pl, there's already a
generic error test that is meant to be used by smoketests.

      or /Error: /  # . . . . . . . . . . . C or smoketest
it would be awesome, but I'm a little wary of touching Tinderbox code. CC'ing coop for a damage estimate.
I'm not that familiar with the tinderbox server-side code, but the error parsing happens in a set of platform-specific libraries, i.e.

http://mxr.mozilla.org/mozilla/source/webtools/tinderbox/ep_windows.pl
http://mxr.mozilla.org/mozilla/source/webtools/tinderbox/ep_mac.pl
http://mxr.mozilla.org/mozilla/source/webtools/tinderbox/ep_unix.pl

It *should* be a simple matter of fixing up those regexps to bring the error parsing up-to-date.
Duplicate of this bug: 380397
*sigh*  This shouldn't require any server-side changes.  You just have to make sure that your errors start with 'Error: ' instead of whatever they do now.
(In reply to comment #8)
> *sigh*  This shouldn't require any server-side changes.  You just have to make
> sure that your errors start with 'Error: ' instead of whatever they do now.
> 

That we can do, but the regexes are still picking up errors where they shouldn't. We're testing JS here, and the console tends to spew information about exceptions that we are triggering intentionally.
Depends on: 394250
Ok, I propose that we fix the false positive errors in bug 394250, and then in this bug we can make our test harnesses produce errors that will get picked up by the log scraping.  It should be as simple as adding "Error:" to the line somewhere.  robcee says he may have to tweak the buildbot log scraping to not break in those cases.
> That we can do, but the regexes are still picking up errors where they
> shouldn't. We're testing JS here, and the console tends to spew information
> about exceptions that we are triggering intentionally.

For this specific set of tests, those errors are expected.  That doesn't necessarily apply to the general case which is what you're proposing changing.  If those exceptions aren't errors, then why not just filter them out in the test scripts?
Simple patch to TinderboxErrorNotifier to allow specifying an errorparser.  We'll need this if we add a unittest specific error parser in bug 394250.  This is against the buildbot darcs repo.
note that we're not compatible with buildbot trunk yet. We're using a forked version of TinderboxMailNotifier from v0.7.5.
From working on bug 394250, we may want to investigate printing the testcase filename on the FAIL line in MochiTest/browser chrome tests, since we can then linkify it to bonsai in the error summary.
This patch causes mochitest to log the test filename in a FAIL line.  This would let us linkify it in the tinderbox logs.  The output just looks like:

*** 686 ERROR FAIL | this is so going to fail |  | /tests/test_bogus.html
Attachment #279393 - Flags: review?(sayrer)
Attachment #279393 - Flags: review?(sayrer) → review+
Wow. Well, if this patch is going to identify the test that failed, maybe my old bug should be closed as a dupe: 

https://bugzilla.mozilla.org/show_bug.cgi?id=370289
'meta: test output in log needs to be matchable to test identity'
Comment on attachment 279393 [details] [diff] [review]
have mochitest print test filename in FAIL lines [checked in]

Ray: that's your bug, so you're welcome to decide it's a dupe.  My plan is to get tests to print the test filename on failure lines only.
Attachment #279393 - Attachment description: have mochitest print test filename in FAIL lines → have mochitest print test filename in FAIL lines [checked in]
Same as above, for browser chrome tests.
Assignee: nobody → ted.mielczarek
Status: NEW → ASSIGNED
Attachment #279596 - Flags: review?(gavin.sharp)
Depends on: 394875
Comment on attachment 279596 [details] [diff] [review]
have browser chrome tests print test filename in FAIL lines [checked in]

This makes the full log a bit redundant, but I guess that's not too big of a deal.

>Index: testing/mochitest/browser-harness.xul

>+        return this.tests.map(function (t) {
>+                                if(!t.pass)

nit: space before opening parenthesis
Attachment #279596 - Flags: review?(gavin.sharp) → review+
Comment on attachment 279596 [details] [diff] [review]
have browser chrome tests print test filename in FAIL lines [checked in]

Checked in with that nit fixed.
Attachment #279596 - Attachment description: have browser chrome tests print test filename in FAIL lines → have browser chrome tests print test filename in FAIL lines [checked in]
Ted - If you have the machinery in place to deterministically identify the test on failure, why not note the test identity on success? Ignoring the success merely loses information. Once the log is generated, one can never get that information back.

Is the size of the logs the issue? Using more compression would be better than forever losing information from the log.
The test being run is already listed, before the individual test results, for both mochitest and the browser chrome output. Why do you need it printed on every single line?
What if one wants to grep for successes also? I just do not consider making the logs more regular, at the cost of repetition, a bad thing. Eliminating repetition is what compression does very well. "zcat foo.gz | grep xxx" is not much harder than "grep xxx foo".
Grep for all thirty-thousand-plus successes?
No, the successes _and_ failures of a particular test. For example. The point is there are other examples. If you decide 'the only question is going to be this', then make that question answerable, what happens when there are more questions?

I can tell you, because I usually ask more questions. The usual response is "why do you want to know that?". Which is not an answer.
(In reply to comment #25)
> I can tell you, because I usually ask more questions. The usual response is
> "why do you want to know that?". Which is not an answer.

It's not an answer, but it's an important question. If you can't justify why you think something should be added, then it shouldn't be added. It's a mistake to assume that everyone will see the benefits to a proposal just because you do.
Comment on attachment 279097 [details] [diff] [review]
allow TinderboxMailNotifier to specify an errorparser [checked in]

This works for me:
http://tinderbox-stage.mozilla.org/showlog.cgi?log=MozillaTest/1188960032.1189002561.26869.gz
Attachment #279097 - Flags: review?(bhearsum)
Yes. Compression is easy. So, why is putting in redundant content to make the log more clear and more simply filterable a big deal?

And, ultimately, if you all do not want to do something for a future benefit, then don't. I have certainly lost that argument before and I will continue to lose it in the future. And then when things need to be redesigned because "we did not know we were going to need to answer those questions", I will just try to keep my mouth shut. We'll see.
(In reply to comment #28)
> Yes. Compression is easy. So, why is putting in redundant content to make the
> log more clear and more simply filterable a big deal?

I don't see how it makes the log "more clear", and I'm not sure that the filtering cases you're trying to support are actually required from the people who use the log. I don't think "I would like X" and "there are many examples of why X is useful" alone is sufficient justification for adding X, especially if adding X has some obvious costs.

> And, ultimately, if you all do not want to do something for a future benefit,
> then don't.

"Future benefit" has to be weighed against present cost. If the purported "future benefit" isn't obvious, or backed by actual use cases, then I don't think it should be given much weight.
Comment on attachment 279097 [details] [diff] [review]
allow TinderboxMailNotifier to specify an errorparser [checked in]

Remembered that Ben is on vacation...
Attachment #279097 - Flags: review?(bhearsum) → review?(rhelmer)
Attachment #279097 - Flags: review?(rhelmer) → review+
Comment on attachment 279097 [details] [diff] [review]
allow TinderboxMailNotifier to specify an errorparser [checked in]

I checked this into CVS, and I filed a ticket to get it upstream:
http://buildbot.net/trac/ticket/94
Attachment #279097 - Attachment description: allow TinderboxMailNotifier to specify an errorparser → allow TinderboxMailNotifier to specify an errorparser [checked in]
This patch broke our Buildbot tree. The culprit is here:
        mail.MailNotifier.__init__(self, fromaddr, categories=categories,
                                   builders=builders, relayhost=relayhost,
                                   subject=subject,
                                   extraRecipients=extraRecipients,
        self.errorparser = errorparser
                                   sendToInterestedUsers=False)

self.errorparser is one line too high. I'm going to attach a patch to fix this.
The aforementioned patch.
Attachment #280666 - Flags: review?(ted.mielczarek)
Comment on attachment 280666 [details] [diff] [review]
fix typo in errorparser patch [checked in]

Oh, crap.  The patch looked like it applied cleanly, I should have checked out the results more closely.  Thanks for the fix.
Attachment #280666 - Flags: review?(ted.mielczarek) → review+
I don't have commit access, can you land this?
Attachment #280666 - Attachment description: fix typo in errorparser patch → fix typo in errorparser patch [checked in]
This looks like it's been fixed for awhile...
Status: ASSIGNED → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
This still needs the production tinderbox to be updated to CVS HEAD, and then the unittest buildbots to specify the unittest errorparser.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Depends on: 399693
Attachment #289658 - Flags: review?(rcampbell) → review+
Attachment #289658 - Attachment description: make unittest master use unittest errorparser → make unittest master use unittest errorparser [checked in]
Over to robcee to update the unit test master.
Assignee: ted.mielczarek → rcampbell
Status: REOPENED → NEW
Fixed!  http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1195656287.1195658458.11132.gz

The TUnit tests will have bogus bonsai links until I get bug 394875 fixed, but that's not really critical.
Assignee: rcampbell → nobody
I always click that accidentally when I mean to just hit submit.
Assignee: nobody → ted.mielczarek
Status: NEW → RESOLVED
Closed: 12 years ago12 years ago
Resolution: --- → FIXED
Component: Testing → Mochitest
Product: Core → Testing
QA Contact: testing → mochitest
Version: Trunk → unspecified
Depends on: 586754
No longer depends on: 394875
You need to log in before you can comment on or make changes to this bug.