Closed Bug 620875 Opened 11 years ago Closed 11 years ago

Intermittent browser_webconsole_bug_595934_message_categories.js | Test timed out followed by failures to give up and stop running

Categories

(DevTools :: General, defect, P1)

x86
macOS
defect

Tracking

(Not tracked)

RESOLVED FIXED
Firefox 4.0b9

People

(Reporter: philor, Assigned: msucan)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 1 obsolete file)

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1292991356.1292994269.23272.gz
Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central debug test mochitest-other on 2010/12/21 20:15:56
s: talos-r3-snow-046

TEST-PASS | chrome://mochitests/content/browser/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js | test #16: message found 'getSelection'
++DOMWINDOW == 221 (0x142d44268) [serial = 3750] [outer = 0x139900a50]
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js | Test timed out

*** This is where you want to have called registerCleanupFunction() at the start of your test, passing it the name of the function where you remove all your observers and clean up, both when you call it when you finish normally and when the harness calls it when you time out. ***

INFO TEST-END | chrome://mochitests/content/browser/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js | finished in 31341ms
TEST-INFO | checking window state
TEST-INFO | before wait for focus -- loaded: complete active window: ([object ChromeWindow @ 0x10cf80c50 (native @ 0x10cf7d5c8)]) chrome://browser/content/browser.xul focused window: ([object XrayWrapper [object Window @ 0x140e37020 (native @ 0x13fdbcce8)]]) about:blank desired window: ([object ChromeWindow @ 0x10cf80c50 (native @ 0x10cf7d5c8)]) chrome://browser/content/browser.xul child window: ([object XrayWrapper [object Window @ 0x140e37020 (native @ 0x13fdbcce8)]]) about:blank docshell visible: true
TEST-INFO | already focused
TEST-INFO | maybe run tests <load:true, focus:true> -- loaded: complete active window: ([object ChromeWindow @ 0x10cf80c50 (native @ 0x10cf7d5c8)]) chrome://browser/content/browser.xul focused window: ([object XrayWrapper [object Window @ 0x140e37020 (native @ 0x13fdbcce8)]]) about:blank desired window: ([object ChromeWindow @ 0x10cf80c50 (native @ 0x10cf7d5c8)]) chrome://browser/content/browser.xul child window: ([object XrayWrapper [object Window @ 0x140e37020 (native @ 0x13fdbcce8)]]) about:blank docshell visible: true
TEST-PASS | chrome://mochitests/content/browser/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js | test #17: error category 'Image'

*** so you don't go passing inside someone else's test

TEST-INFO | chrome://mochitests/content/browser/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js | Console message: [JavaScript Error: "Image corrupt or truncated: http://example.com/browser/toolkit/components/console/hudservice/tests/browser/test-bug-595934-image.jpg" {file: "http://example.com/browser/toolkit/components/console/hudservice/tests/browser/test-bug-595934-image.jpg" line: 0}]
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "Component returned failure code: 0x80004002 (NS_NOINTERFACE) [nsIInterfaceRequestor.getInterface]"  nsresult: "0x80004002 (NS_NOINTERFACE)"  location: "JS frame :: resource:///modules/HUDService.jsm :: ConsoleUtils_getParents :: line 5053"  data: no]
************************************************************
WARNING: Overflowed nscoord_MAX in conversion to nscoord: file ../../dist/include/nsCoord.h, line 359
TEST-START | chrome://mochitests/content/browser/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_597103_deactivateHUDForContext_unfocused_window.js
JS Component Loader: WARNING chrome://mochitests/content/browser/toolkit/components/console/hudservice/tests/browser/head.js:54
                     anonymous function does not always return a value
TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js | test #17: error category 'Image' - Got chrome javascript, expected Image

*** or failing when it's someone else's test you're observing
Attached patch proposed fix (obsolete) — Splinter Review
This patch improves the browser_webconsole_bug_595934_message_categories.js test by adding better resistance to failures, as suggested using a registered cleanup function.

The test failure itself: I have no clue why that might happen. The getselection.html page is loaded, the console service observer listens for errors, and checks if they show up in the web console or not. The only possibility for failure is if the observer executes performTest() earlier than the web console output. I already have performTest() inside executeSoon(). To further push the call later ... would mean using setTimeout() or perhaps a web console output DOMNodeInserted event listener. Both seem overkill.

Thoughts?
Assignee: nobody → mihai.sucan
Status: NEW → ASSIGNED
Blocks: devtools4
Priority: -- → P1
Comment on attachment 499265 [details] [diff] [review]
proposed fix

Asking for review.
Attachment #499265 - Flags: review?(sdwilsh)
Comment on attachment 499265 [details] [diff] [review]
proposed fix

>diff --git a/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js b/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js

> function testNext() {
>+  if (testEnded) {
>+    return;

>+        if (!testEnded) {
>+          TESTS[pos].onload(aEvent);

Won't this always be true, given the above?

Rather than adding the testEnded flag, can't you just registerCleanupFunction the removal of the listener to achieve the same effect?
(In reply to comment #3)
> Comment on attachment 499265 [details] [diff] [review]
> proposed fix
> 
> >diff --git a/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js b/toolkit/components/console/hudservice/tests/browser/browser_webconsole_bug_595934_message_categories.js
> 
> > function testNext() {
> >+  if (testEnded) {
> >+    return;
> 
> >+        if (!testEnded) {
> >+          TESTS[pos].onload(aEvent);
> 
> Won't this always be true, given the above?

The former stops the code from moving on to the next test, if the testEnded *just* then. The latter check prevents the async load event handler from continuing its own work, if the test just ended.

> Rather than adding the testEnded flag, can't you just registerCleanupFunction
> the removal of the listener to achieve the same effect?

The testEnd() function is registered as a cleanup function.
Ok, I was a bit confused about the logic. But my point is that it's cleaner to have a registered cleanup function that just removes all observers/listeners, rather than having them continue existing but do nothing because you're tracking test completion state in a testEnded flag. This might require you to keep an array of added listeners, but that still seems better than the testEnded flag.
(In reply to comment #5)
> Ok, I was a bit confused about the logic. But my point is that it's cleaner to
> have a registered cleanup function that just removes all observers/listeners,
> rather than having them continue existing but do nothing because you're
> tracking test completion state in a testEnded flag. This might require you to
> keep an array of added listeners, but that still seems better than the
> testEnded flag.

Maintaining an array is not needed, the tab will close anyway. The only listener we need to remove is the Service.console one, which is removed by the testEnd() function (which is registered as a cleanup function).

To simplify, I can just go ahead and remove the testEnded flag. I can let performTest() and onload() execute, and they'll fail only once if bad things happen.
(In reply to comment #1)
> The test failure itself: I have no clue why that might happen. The
> getselection.html page is loaded, the console service observer listens for
> errors, and checks if they show up in the web console or not. The only
> possibility for failure is if the observer executes performTest() earlier than
> the web console output. I already have performTest() inside executeSoon(). To
> further push the call later ... would mean using setTimeout() or perhaps a web
> console output DOMNodeInserted event listener. Both seem overkill.
setTimeout isn't reliable, but a DOMNodeInserted listener is the right way to go for a deterministic test.  We should do that, since that is part of the intermittent failure here.

(In reply to comment #6)
> Maintaining an array is not needed, the tab will close anyway. The only
> listener we need to remove is the Service.console one, which is removed by the
> testEnd() function (which is registered as a cleanup function).
The tab will close in the case where it times out still?  If so, we shouldn't need these flags anyway since all the other observers will get cleaned up by the tab close, right?
(In reply to comment #7)
> (In reply to comment #1)
> > The test failure itself: I have no clue why that might happen. The
> > getselection.html page is loaded, the console service observer listens for
> > errors, and checks if they show up in the web console or not. The only
> > possibility for failure is if the observer executes performTest() earlier than
> > the web console output. I already have performTest() inside executeSoon(). To
> > further push the call later ... would mean using setTimeout() or perhaps a web
> > console output DOMNodeInserted event listener. Both seem overkill.
> setTimeout isn't reliable, but a DOMNodeInserted listener is the right way to
> go for a deterministic test.  We should do that, since that is part of the
> intermittent failure here.

Agreed.


> (In reply to comment #6)
> > Maintaining an array is not needed, the tab will close anyway. The only
> > listener we need to remove is the Service.console one, which is removed by the
> > testEnd() function (which is registered as a cleanup function).
> The tab will close in the case where it times out still?  If so, we shouldn't
> need these flags anyway since all the other observers will get cleaned up by
> the tab close, right?

Correct, hence I suggested we can remove the flag entirely.

Thanks for looking into the patch! Will update it.
Attached patch updated patchSplinter Review
Updated the patch as requested. Thanks for your comments!
Attachment #499265 - Attachment is obsolete: true
Attachment #500098 - Flags: review?(sdwilsh)
Attachment #499265 - Flags: review?(sdwilsh)
Whiteboard: [orange] → [patchclean:1228][orange]
Comment on attachment 500098 [details] [diff] [review]
updated patch

r=sdwilsh
Attachment #500098 - Flags: review?(sdwilsh)
Attachment #500098 - Flags: review+
Attachment #500098 - Flags: approval2.0+
Thanks!
Whiteboard: [patchclean:1228][orange] → [patchclean:1228][orange][checkin]
http://hg.mozilla.org/mozilla-central/rev/27822e3c3937
Status: ASSIGNED → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Whiteboard: [patchclean:1228][orange][checkin] → [orange]
Target Milestone: --- → Firefox 4.0b9
Whiteboard: [orange]
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.