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

RESOLVED FIXED in mozilla32

Status

()

Core
JavaScript Engine
RESOLVED FIXED
5 years ago
4 years ago

People

(Reporter: emorley, Assigned: emorley)

Tracking

(Blocks: 2 bugs)

Trunk
mozilla32
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(1 attachment, 1 obsolete attachment)

(Assignee)

Description

5 years ago
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?
(Assignee)

Comment 1

5 years ago
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)
(Assignee)

Comment 3

5 years ago
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).
(Assignee)

Comment 4

5 years ago
So I don't misplace it, I've been grepping with:
^[ \t]*print[ \t]*\([ \t]*(?!BUGNUMBER|beginTag|['"][A-Za-z]+)
(Assignee)

Comment 5

5 years ago
Better regex:
catch[ \t]*\([ \t]*([A-Za-z]+)[ \t]*\)[\s]*[\{].*print[ \t]*\([ \t]*\1[^\r\n]*\)

(with . matching newline)
(Assignee)

Comment 6

5 years ago
Created attachment 722796 [details] [diff] [review]
Patch v1

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
(Assignee)

Comment 7

5 years ago
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.
(Assignee)

Updated

5 years ago
Whiteboard: [waiting on repeat try run]
(Assignee)

Comment 10

5 years ago
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
(Assignee)

Comment 11

5 years ago
(Also bug 849239 made this not as bad as it was originally)
(Assignee)

Updated

5 years ago
Whiteboard: [waiting on repeat try run] → [needs repeat try run]
(Assignee)

Updated

5 years ago
Blocks: 910272
(Assignee)

Updated

5 years ago
Blocks: 910271
(Assignee)

Comment 12

4 years ago
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
(Assignee)

Comment 13

4 years ago
New try push, to remind me what broke last time:
remote:   https://tbpl.mozilla.org/?tree=Try&rev=14b30f33914b
(Assignee)

Comment 14

4 years ago
Created attachment 8427608 [details] [diff] [review]
Prefix test print()s with "TEST-INFO | "

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)
(Assignee)

Updated

4 years ago
Attachment #722796 - Attachment is obsolete: true
(Assignee)

Updated

4 years ago
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
Last Resolved: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla32
You need to log in before you can comment on or make changes to this bug.