Closed Bug 898593 Opened 10 years ago Closed 9 years ago

Intermittent test_bug413958.html | monitorConsole | extra message | {"message": (whatever message it might be) ...

Categories

(Core :: General, defect)

Product:
Core
Component:
General
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla28
Tracking Flags:
Tracking Status
firefox26 --- wontfix
firefox27 --- fixed
firefox28 --- fixed
firefox-esr24 --- fixed
b2g-v1.2 --- fixed

People

(Reporter: RyanVM, Assigned: adw)

References

Details

(Keywords: intermittent-failure)

Attachments

(2 files)

make monitorConsole ignore unexpected messages by default
4.04 KB, patch
ted
: review+
Details | Diff | Splinter Review
let callers forbid particular messages
5.39 KB, patch
ted
: review+
Details | Diff | Splinter Review 
https://tbpl.mozilla.org/php/getParsedLog.php?id=25753685&tree=Fx-Team

Rev5 MacOSX Mountain Lion 10.8 fx-team opt test mochitest-5 on 2013-07-25 21:09:24 PDT for push 5a60a08e6899
slave: talos-mtnlion-r5-054

21:12:22     INFO -  5851 INFO TEST-PASS | /tests/layout/style/test/test_bug413958.html | monitorConsole | [2].errorMessage value - "Expected ',' or '{' but found '?'.  Ruleset ignored due to bad selector." contains /Ruleset ignored due to bad selector/
21:12:22     INFO -  5852 INFO TEST-PASS | /tests/layout/style/test/test_bug413958.html | monitorConsole | [2].lineNumber present
21:12:22     INFO -  5853 INFO TEST-PASS | /tests/layout/style/test/test_bug413958.html | monitorConsole | [2].lineNumber value
21:12:22     INFO -  5854 INFO TEST-PASS | /tests/layout/style/test/test_bug413958.html | monitorConsole | [2].columnNumber present
21:12:22     INFO -  5855 INFO TEST-PASS | /tests/layout/style/test/test_bug413958.html | monitorConsole | [2].columnNumber value
21:12:22     INFO -  5856 INFO TEST-PASS | /tests/layout/style/test/test_bug413958.html | monitorConsole | [2].sourceLine present
21:12:22     INFO -  5857 INFO TEST-PASS | /tests/layout/style/test/test_bug413958.html | monitorConsole | [2].sourceLine value
21:12:22     INFO -  5858 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/style/test/test_bug413958.html | monitorConsole | extra message | {"message":"1374811942685\tServices.HealthReport.HealthReporter\tWARN\tSaved state file does not exist.\n","errorMessage":null,"sourceName":null,"sourceLine":null,"lineNumber":null,"columnNumber":null,"category":null,"windowID":null,"isScriptError":false,"isWarning":false,"isException":false,"isStrict":false}
21:12:22     INFO -  5859 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/style/test/test_bug413958.html | monitorConsole | extra message | {"message":"1374811942685\tServices.HealthReport.HealthReporter\tWARN\tNo prefs data found.\n","errorMessage":null,"sourceName":null,"sourceLine":null,"lineNumber":null,"columnNumber":null,"category":null,"windowID":null,"isScriptError":false,"isWarning":false,"isException":false,"isStrict":false}
Nothing should have changed in FHR to make this error. Did something change in automation?

Furthermore, this error message is probably a side-effect of a test that explicitly tests what happens when the "saved state file does not exist." If we now can't write tests that write errors to the console because they are reported as automation errors, that is dumb because it discourages comprehensive test writing.

Perhaps I am misinterpreting what's going on or am wrong in my expectation that it's appropriate to write errors to the console.
Flags: needinfo?(ryanvm)
Flags: needinfo?(ryanvm)
Yep, that's pretty much where we are.

People continue to write tests which assume that they completely own the console, and that nothing else should be allowed to write to it while their test is running.

People continue to write a browser which assumes that it can write to the console.

Nobody has the slightest willingness to do anything but point at the other side.
Component: Client: Desktop → General
Product: Firefox Health Report → Core
Summary: Intermittent test_bug413958.html | monitorConsole | extra message | {"message":"1374811942685\tServices.HealthReport.HealthReporter\tWARN\tSaved state file does not exist.\n","errorMessage":null,"sourceName":null,"sourceLine":null,"lineNumber":null," ... → Intermittent test_bug413958.html | monitorConsole | extra message | {"message": (whatever message it might be) ...
Version: unspecified → Trunk
(In reply to Phil Ringnalda (:philor) from comment #12)
> Yep, that's pretty much where we are.
> 
> People continue to write tests which assume that they completely own the
> console, and that nothing else should be allowed to write to it while their
> test is running.
> 
> People continue to write a browser which assumes that it can write to the
> console.
> 
> Nobody has the slightest willingness to do anything but point at the other
> side.

Gavin, please could you find someone to drive this?
Flags: needinfo?(gavin.sharp)
Offer at bug 874743 comment 138 still stands!

Drew, can you take this bug and bug 874743, and fix them by changing the test's console observer to fail gracefully in the face of unexpected console messages appearing during the test? Similar to how e.g. http://hg.mozilla.org/mozilla-central/annotate/35b73bb96ca0/browser/devtools/webconsole/test/browser_webconsole_bug_595934_message_categories.js#l86 works.
Assignee: nobody → adw
Flags: needinfo?(gavin.sharp)
OS: Mac OS X → All
Hardware: x86_64 → All
Thank you :-)
Sure.
Status: NEW → ASSIGNED
(In reply to Phil Ringnalda (:philor) from comment #12)
> People continue to write tests which assume that they completely own the
> console, and that nothing else should be allowed to write to it while their
> test is running.

I agree with Phil.  I think SimpleTest.monitorConsole is fundamentally flawed because it doesn't allow for unexpected messages at all, but there is no guarantee that the only messages that appear while a test is running are those related to the test.  You might say that unexpected messages reveal a real problem in whatever caused them to appear.  Maybe, maybe not.  Comment 157 likely doesn't, bug 900953 maybe does.  It's not at all clear what caused the ones in comment 158.

This patch adds a forbidUnexpectedMsgs parameter to SimpleTest.monitorConsole.  If true, then monitorConsole behaves like it does now, logging failures when unexpected messages appear.  If false, unexpected messages are ignored.  This doesn't change any callers, so they all get the new ignore-unexpected-messages behavior by default.
Attachment #827252 - Flags: review?(ted)
Comment on attachment 827252 [details] [diff] [review]
make monitorConsole ignore unexpected messages by default

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

Sorry for the long delay here, I lost track of my review queue. I apologize profusely.

It sucks that we'll be letting random things slip through, but I guess due to the async nature of our codebase there's not much we can do about this. There aren't any tests that want to forbid specific console messages, are there?
Attachment #827252 - Flags: review?(ted) → review+
Not that I know of... They ought to be examining the console by hand if so, rather than using monitorConsole.
It's good you raised that question.  I looked at all the callers of monitorConsole and related functions:

Three monitorConsole callers:
/content/base/test/test_bug708620.html
/content/events/test/test_bug489671.html
/parser/htmlparser/tests/mochitest/test_bug672453.html

Two expectConsoleMessages callers:
/layout/style/test/test_parser_diagnostics_unprintables.html
/layout/style/test/test_bug413958.html

Two runTestExpectingConsoleMessages callers:
/content/base/test/test_bug513194.html
/content/base/test/test_bug631615.html

It's hard to tell with 100% certainty, but it's pretty clear that all but the last simply check for the presence of messages.  test_bug631615.html checks for the absence of messages, so this patch needs to accommodate it.  Let me see how to do that.
Blocks: 940489
This adds onto the previous patch a little.  It lets callers forbid particular messages by setting a `forbid` property on message patterns.  It updates test_bug631615.html to forbid the error message whose absence it's testing.  This should fix bug 940489, too.

At first I had separate expectedMsgs and forbiddenMsgs parameters, but the extra forbiddenMsgs parameter would require updating expectConsoleMessages() callers (assuming that forbiddenMsgs would come after `msgs` and before `continuation`), which I didn't want to do.  So that's why I went with a `forbid` property.
Attachment #8342838 - Flags: review?(ted)
Comment on attachment 8342838 [details] [diff] [review]
let callers forbid particular messages

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

Excellent!
Attachment #8342838 - Flags: review?(ted) → review+
https://hg.mozilla.org/mozilla-central/rev/ffc6dc19cc05
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla28
Blocks: 927753
Blocks: 905809
You need to log in before you can comment on or make changes to this bug.