379327 - make tinderbox logs suck less when tests fail

Status: RESOLVED FIXED

(Testing :: Mochitest, defect)

Description

[Robert Sayre]

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

Comment 1

[:Gavin Sharp [email: [e-mail]]]

I filed this as bug 374642 when we had talked about it last.

Comment 4

[Robert Sayre]

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

Comment 5

[Rob Campbell [:rc] (:robcee)]

it would be awesome, but I'm a little wary of touching Tinderbox code. CC'ing coop for a damage estimate.

Comment 6

[Chris Cooper [:coop] (he/him)]

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.

Comment 8

[cls]

*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.

Comment 9

[Robert Sayre]

(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.

Comment 10

[(not currently active) Ted Mielczarek]

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.

Comment 11

[cls]

> 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?

Comment 12

[(not currently active) Ted Mielczarek]

Attachment: allow TinderboxMailNotifier to specify an errorparser [checked in]

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.

Comment 13

[Rob Campbell [:rc] (:robcee)]

note that we're not compatible with buildbot trunk yet. We're using a forked version of TinderboxMailNotifier from v0.7.5.

Comment 14

[(not currently active) Ted Mielczarek]

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.

Comment 15

[(not currently active) Ted Mielczarek]

Attachment: have mochitest print test filename in FAIL lines [checked in]

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

Comment 16

[Ray Kiddy]

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 17

[(not currently active) Ted Mielczarek]

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.

Comment 18

[(not currently active) Ted Mielczarek]

Attachment: have browser chrome tests print test filename in FAIL lines [checked in]

Same as above, for browser chrome tests.

Comment 19

[:Gavin Sharp [email: [e-mail]]]

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

Comment 20

[(not currently active) Ted Mielczarek]

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.

Comment 21

[Ray Kiddy]

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.

Comment 22

[:Gavin Sharp [email: [e-mail]]]

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?

Comment 23

[Ray Kiddy]

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".

Comment 24

[Jeff Walden [:Waldo]]

Grep for all thirty-thousand-plus successes?

Comment 25

[Ray Kiddy]

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.

Comment 26

[:Gavin Sharp [email: [e-mail]]]

(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 27

[(not currently active) Ted Mielczarek]

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

Comment 28

[Ray Kiddy]

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.

Comment 29

[:Gavin Sharp [email: [e-mail]]]

(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 30

[(not currently active) Ted Mielczarek]

Comment on attachment 279097 [details] [diff] [review]
allow TinderboxMailNotifier to specify an errorparser [checked in]

Remembered that Ben is on vacation...

Comment 31

[(not currently active) Ted Mielczarek]

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

Comment 32

[[e-mail] (:bhearsum)]

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.

Comment 33

[[e-mail] (:bhearsum)]

Attachment: fix typo in errorparser patch [checked in]

The aforementioned patch.

Comment 34

[(not currently active) 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.

Comment 35

[[e-mail] (:bhearsum)]

I don't have commit access, can you land this?

Comment 36

[[e-mail] (:bhearsum)]

This looks like it's been fixed for awhile...

Comment 37

[(not currently active) Ted Mielczarek]

This still needs the production tinderbox to be updated to CVS HEAD, and then the unittest buildbots to specify the unittest errorparser.

Comment 38

[(not currently active) Ted Mielczarek]

Attachment: make unittest master use unittest errorparser [checked in]

Comment 39

[(not currently active) Ted Mielczarek]

Over to robcee to update the unit test master.

Comment 40

[(not currently active) Ted Mielczarek]

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.

Comment 41

[(not currently active) Ted Mielczarek]

I always click that accidentally when I mean to just hit submit.