583155 - jsreftest is very noisy

Status: RESOLVED FIXED

(Testing :: General, defect)

Description

[Chris AtLee [:catlee]]

jsreftest generates very large (~15MB) log files on opt and debug builds, for all platforms.

This much data can take a while to process, so if there is any way to reduce the output, it would help out the infrastructure a lot.

Comment 1

[Chris AtLee [:catlee]]

e.g. http://tinderbox.mozilla.org/Firefox/1280441266.1280445499.5270.gz

Comment 2

[Bob Clary [:bc] (inactive)]

(In reply to comment #1)
> e.g. http://tinderbox.mozilla.org/Firefox/1280441266.1280445499.5270.gz

This doesn't appear to be a jstestbrowser.log but mochitest 1/5.

Looking at a recent jsreftest example with 168342 lines and breaking down the line counts, I see:

inflating|extracting 20916
^WARNING 43
DOMWINDOW 11254
DOCSHELL 10
^STATUS: 3398
^begin test 2754
REFTEST INFO 3112
REFTEST TEST-START 2810
REFTEST TEST-(UNEXPECTED|KNOWN)?-?(PASS|FAIL) 54992
^ (PASSED|FAILED) 8243

Subtracting these from the total leaves almost 68,000 lines.

"begin test" is no longer as useful since TEST-START was added, and requires the test to output it which newer tests no longer do. It can be removed. Much of the remaining output is the "real time" output of the test results which are replicated in the REFTEST output so long as the browser doesn't crash. I'll work up a patch and see what kind of benefit I can get there.

Comparing to a mochi-5 example with 70872 lines I see

inflating|extracting 20916
^WARNING 1721
DOMWINDOW 2274
DOCSHELL 586
INFO 18134

The jstests may be noisy, but there are other areas that can be improved as well. Eliminating the inflating|extracting messages by using -q on unzip would save a great deal on all logs especially on a percentage basis for mochi tests. What is the additional overhead of having all tests packaged together, passed around and unzipped everywhere? What is the benefit of extracting and specifying only those directories in the test archive that are needed for the particular test run?

Comment 3

[Chris AtLee [:catlee]]

Ah, sorry, here is a jsreftest log: http://tinderbox.mozilla.org/Firefox/1280491356.1280492956.21767.gz

Comment 4

[Chris AtLee [:catlee]]

(In reply to comment #2)
> The jstests may be noisy, but there are other areas that can be improved as
> well. Eliminating the inflating|extracting messages by using -q on unzip would
> save a great deal on all logs especially on a percentage basis for mochi tests.
> What is the additional overhead of having all tests packaged together, passed
> around and unzipped everywhere? What is the benefit of extracting and
> specifying only those directories in the test archive that are needed for the
> particular test run?

So, there's 1.6MB of log data before the tests even run.  Cutting out the output from unpacking the tests brings that down to ~45k.  We've resisted cutting this out before, since it's proven useful in certain cases to know exactly which tests were unpacked.

Is there a simple way to determine exactly which directories in the archive need to be extracted for a particular test suite?

Comment 5

[Bob Clary [:bc] (inactive)]

(In reply to comment #4)

> Is there a simple way to determine exactly which directories in the archive
> need to be extracted for a particular test suite?

Not that simple unfortunately. The reftest directory contains some scripts at the top level that are required for any reftest based test. reftest/tests contains a mixture of normal reftests and crashtests. If they were segregated, it would be simpler to only extract what is needed. Perhaps a followup bug.

bin/ and certs/ are probably required for all tests.

I think this would work, but I'm not sure of the benefit vs. complexity.

mochi tests   : mochitest/, bin/, certs/
mozmill tests : mozmill/,   bin/, certs/
xpcshell tests: xpcshell/,  bin/, certs/
crash tests   : reftest/,   bin/, certs/
reftests      : reftest/,   bin/, certs/
jsreftests    : reftest/,   bin/, certs/, jsreftest/

doing a find | wc -l on the dirs gives

bin      : 17
certs    : 11
jsreftest: 3641
mochitest: 5926
mozmill  : 584
reftest  : 10164
xpcshell : 1488

Comment 6

[Bob Clary [:bc] (inactive)]

Attachment: patch v1 (gzipped)

This patch eliminates the default output of the test results when running under reftest. Apart from individually editing the most egregious tests, I think this is good enough.

It also eliminates the begin test output and the corresponding need to set gTestsuite, gTestsubsuite and gTestfile since they are not absolutely needed and aren't always set in newer tests anyway.

mrbkap: I had to munge js1_7/regexp/yflag.js since the call to reportCompare contains a regexp match that interfered with the test. That is the part I'm looking for a review on.

dmandelin: This won't interfere with jstests.py will it?

Running the jsreftests locally on my macbook I see the following:

before: 145457 lines, 14M
after :  85819 lines, 11M

I'll attach them for comparison.

Comment 7

[Bob Clary [:bc] (inactive)]

Attachment: jstestbrowser-before.log.bz2

Comment 8

[Bob Clary [:bc] (inactive)]

Attachment: jstestbrowser-after.log.bz2

Comment 9

[David Mandelin [:dmandelin]]

Comment on attachment 461549 [details]
patch v1 (gzipped)

It's hard to give feedback based on the full logs. A small excerpt would make it easier to understand what the change is. Also, it would be nice to see an example of what a test failure looks like in the two versions, and what a crash looks like. Anyway, based on glancing at the attached examples, I don't see anything to object to.

Some general remarks on where we might want to go with this:

- I agree with the suggestion of removing a lot of the preliminary stuff that gets logged before any tests actually run.
- Tests passing is not terribly interesting; for my own part, I'd be OK with suppressing all output on passing tests.
- The important thing is to make it easy to understand what happened in a case of failure. Part of this is removing irrelevant information, as above. The current messages that get printed when there is a failure are fine. The current message system also tells you what test you crashed on if you crashed. It's really important to keep that information.

Comment 10

[Bob Clary [:bc] (inactive)]

This will teach me to do a jstest patch against mozilla-central. I had to munge the patch a bit due to recent merges from tracemonkey. Apart from some new tests from Waldo, the only change is to remove gTestfile from narcissus/shell.js.

taustin: since this patch will remove gTestfile completely, I don't think it will cause you problems. Let me know if it will. 

I'll commit the new patch after a try server run and after the tree opens after b3 related work.

Comment 11

[Tom Austin]

That should be fine.  Once this is in TraceMonkey, that should let me simplify the testing setup for Narcissus as well.  Thanks for the heads up.

Comment 12

[Bob Clary [:bc] (inactive)]

http://hg.mozilla.org/tracemonkey/rev/479cedf27101

the next merge will take care of mozilla-central. catlee: I hope this is sufficient. If not, let me know.

Comment 13

[Robert Sayre]

http://hg.mozilla.org/mozilla-central/rev/479cedf27101