Closed Bug 829684 Opened 8 years ago Closed 6 years ago

jsreftests should prefix test output in stdout to avoid false TBPL positives for expected exceptions

Categories

(Core :: JavaScript Engine, defect)

defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla32

People

(Reporter: emorley, Assigned: emorley)

References

(Blocks 2 open bugs)

Details

Attachments

(1 file, 1 obsolete file)

Bug 816971 is attempting to improve TBPL's ability to show Python exceptions in it's annotated summary.

However, testing the patch there showed that jsreftests output many (presumably) expected JS exceptions to stdout, which match the regex in that bug, and would cause confusion if we landed this on TBPL production.

There were 30+ such false positives in a fedora opt jsreftest run - some examples:

REFTEST TEST-START | file:///home/cltbld/talos-slave/test/build/jsreftest/tests/jsreftest.html?test=e4x/Regress/regress-383255.js | 127 / 3202 (3%)
BUGNUMBER: 383255
STATUS: Do not assert: JS_UPTRDIFF(fp->sp, fp->spbase) <= depthdiff
TypeError: invalid XML name 0
REFTEST TEST-PASS | file:///home/cltbld/talos-slave/test/build/jsreftest/tests/jsreftest.html?test=e4x/Regress/regress-383255.js | Section 1 of test - Do not assert: JS_UPTRDIFF(fp->sp, fp->spbase) <= depthdiff  item 1

...

REFTEST TEST-START | file:///home/cltbld/talos-slave/test/build/jsreftest/tests/jsreftest.html?test=js1_5/Regress/regress-410852.js | 2061 / 3202 (64%)
BUGNUMBER: 410852
STATUS: Valgrind errors in jsemit.cpp
Note: You must run this test under valgrind to determine if it passes
SyntaxError: function statement requires a name
REFTEST TEST-PASS | file:///home/cltbld/talos-slave/test/build/jsreftest/tests/jsreftest.html?test=js1_5/Regress/regress-410852.js | Valgrind errors in jsemit.cpp  item 1

...

REFTEST TEST-START | file:///home/cltbld/talos-slave/test/build/jsreftest/tests/jsreftest.html?test=js1_7/regress/regress-373828.js | 2704 / 3202 (84%)
BUGNUMBER: 373828
STATUS: Do not assert: op == JSOP_LEAVEBLOCKEXPR ? fp->spbase + OBJ_BLOCK_DEPTH(cx, obj) == sp - 1 : fp->spbase + OBJ_BLOCK_DEPTH(cx, obj) == sp
ReferenceError: d is not defined

I propose that we add a prefix to the test output - something like "INFO: " - which would fit in with the "BUGNUMBER: " / "STATUS: " format already used.

Sound acceptable?
terrence, does the proposal in comment 0 sound acceptable? :-)
Flags: needinfo?(terrence)
That sounds reasonable, however, for the two extant tests that you showed, there is no reason for them to be printing at all: the prints look like debugging code that should have been removed. If there are only ~30 of these tests, it would probably be easier to just fix the tests.

Also, on TBPL, these tests run in the browser with the -reftest flag and not under the shell harness: tests/jstests.py. Thus, I don't really know what prints these messages, so I don't know how hard it would be to update the output.

Good luck!
Flags: needinfo?(terrence)
I think the print() comes from http://mxr.mozilla.org/mozilla-central/source/js/src/tests/browser.js#33

But yeah would be good to fix the tests in addition, if those lines are in fact unwanted (MXR says ~60-70 of them).
So I don't misplace it, I've been grepping with:
^[ \t]*print[ \t]*\([ \t]*(?!BUGNUMBER|beginTag|['"][A-Za-z]+)
Better regex:
catch[ \t]*\([ \t]*([A-Za-z]+)[ \t]*\)[\s]*[\{].*print[ \t]*\([ \t]*\1[^\r\n]*\)

(with . matching newline)
Attached patch Patch v1 (obsolete) — Splinter Review
I've broken out the "remove leftover debugging prints" part to bug 849239.

However I feel we should still prefix, like we do for every other testsuite.

https://tbpl.mozilla.org/?tree=Try&rev=5feef563aa5e
Assignee: general → emorley
Status: NEW → ASSIGNED
This prefixes a few other things unintentionally (remembering from my initial glance at the try run). However try has since been reset, so I'll need to repush to find out what it was again.
Comment on attachment 722796 [details] [diff] [review]
Patch v1

Review of attachment 722796 [details] [diff] [review]:
-----------------------------------------------------------------

If you've manually checked the output (note: this is the shell harness and does not run on TBPL), then this solution seems fine.
Attachment #722796 - Flags: feedback+
(In reply to Terrence Cole [:terrence] from comment #8)
> If you've manually checked the output (note: this is the shell harness and
> does not run on TBPL), then this solution seems fine.

Oh, nevermind, we also load browser.js when running in the shell, so this is totally fine.
Whiteboard: [waiting on repeat try run]
iirc the patch here was broken, but try got reset so it'll need to be submitted again to figure out what.

Unassigning for the moment, since I'm not actively working on it.
Assignee: emorley → general
Status: ASSIGNED → NEW
(Also bug 849239 made this not as bad as it was originally)
Whiteboard: [waiting on repeat try run] → [needs repeat try run]
Blocks: 910272
Blocks: 910271
Reassigning, since this would fix the false log parser positives on output like:
https://tbpl.mozilla.org/php/getParsedLog.php?id=40154932&tree=Mozilla-Central#error0
Windows 7 32-bit mozilla-central opt test jsreftest on 2014-05-21 21:26:20 PDT for push b40296602083
21:33:40     INFO -  REFTEST TEST-START | file:///C:/slave/test/build/tests/jsreftest/tests/jsreftest.html?test=js1_5/Scope/regress-446026-01.js
21:33:40     INFO -  REFTEST TEST-LOAD | file:///C:/slave/test/build/tests/jsreftest/tests/jsreftest.html?test=js1_5/Scope/regress-446026-01.js | 2146 / 6755 (31%)
21:33:40     INFO -  BUGNUMBER: 446026
21:33:40     INFO -  STATUS: brian loves eval(s, o)
21:33:40     INFO -  ReferenceError: a is not defined | undefined | 45
21:33:40     INFO -  1
21:33:40     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/jsreftest/tests/jsreftest.html?test=js1_5/Scope/regress-446026-01.js | brian loves eval(s, o)  item 1
21:33:40     INFO -  REFTEST TEST-PASS | file:///C:/slave/test/build/tests/jsreftest/tests/jsreftest.html?test=js1_5/Scope/regress-446026-01.js | brian loves eval(s, o)  item 2
21:33:40     INFO -  REFTEST INFO | Loading a blank page
21:33:40     INFO -  REFTEST TEST-END | file:///C:/slave/test/build/tests/jsreftest/tests/jsreftest.html?test=js1_5/Scope/regress-446026-01.js

...where TBPL matches against:
21:33:40     INFO -  ReferenceError: a is not defined | undefined | 45
Assignee: general → emorley
Status: NEW → ASSIGNED
New try push, to remind me what broke last time:
remote:   https://tbpl.mozilla.org/?tree=Try&rev=14b30f33914b
Now prefixing with "TEST-INFO | " for consistency with other harnesses.
Ideally we'd have tests using printInfo() and differentiate more, since there's the odd overlap with things that don't really need a prefix, but from looking through the logs there's nothing that's going to be problematic, and in general I think this is a net win for now - without the effort of rewriting half the test suite.

Try run:
https://tbpl.mozilla.org/?tree=Try&rev=51039c76f6e3
Attachment #8427608 - Flags: review?(terrence)
Attachment #722796 - Attachment is obsolete: true
Whiteboard: [needs repeat try run]
Comment on attachment 8427608 [details] [diff] [review]
Prefix test print()s with "TEST-INFO | "

Review of attachment 8427608 [details] [diff] [review]:
-----------------------------------------------------------------

Nice! r=me
Attachment #8427608 - Flags: review?(terrence) → review+
https://hg.mozilla.org/mozilla-central/rev/e368bba6dbbc
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla32
You need to log in before you can comment on or make changes to this bug.