Closed Bug 594909 Opened 14 years ago Closed 14 years ago

Intermittent failure in browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is visible

Categories

(Firefox Graveyard :: Panorama, defect, P1)

x86
Windows 7
defect

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: ehsan.akhgari, Assigned: iangilman)

References

Details

(Keywords: intermittent-failure, Whiteboard: [qa-])

Attachments

(1 file, 5 obsolete files)

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1284059797.1284061653.5459.gz
Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central debug test mochitest-other on 2010/09/09 12:16:37

TEST-START | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
Chrome file doesn't exist: /Users/cltbld/talos-slave/mozilla-central_snowleopard-debug_test-mochitest-other/build/mochitest/browser/browser/base/content/test/tabview/head.js
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is hidden
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View button exists
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is hidden
WARNING: Overflowed nscoord_MAX in conversion to nscoord: file ../../dist/include/nsCoord.h, line 359
TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is visible
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is visible
TEST-INFO | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Console message: tabview assert: must already be linkedTabItems__update([object XULElement])@chrome://browser/content/tabview.js:4548
TabItems_heartbeat()@chrome://browser/content/tabview.js:4647
TabItems_resumePainting()@chrome://browser/content/tabview.js:4685
()@chrome://browser/content/tabview.js:4382
(-6)@chrome://browser/content/tabview.js:600

TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is hidden
WARNING: Overflowed nscoord_MAX in conversion to nscoord: file ../../dist/include/nsCoord.h, line 359
WARNING: Overflowed nscoord_MAX in conversion to nscoord: file ../../dist/include/nsCoord.h, line 359
WARNING: Overflowed nscoord_MAX in conversion to nscoord: file ../../dist/include/nsCoord.h, line 359
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is visible
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is hidden
TEST-INFO | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Test took 1.494s to complete

TEST-INFO | checking window state
TEST-INFO | before wait for focus -- loaded: complete active window: ([object ChromeWindow @ 0x10ff01f70 (native @ 0x109ffaa38)]) chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper [object Window @ 0x1119e7740 (native @ 0x114ff23c8)]]) about:blank desired window: ([object ChromeWindow @ 0x10ff01f70 (native @ 0x109ffaa38)]) chrome://browser/content/browser.xul child window: ([object XPCNativeWrapper [object Window @ 0x1119e7740 (native @ 0x114ff23c8)]]) about:blank docshell visible: true
TEST-INFO | already focused
TEST-INFO | maybe run tests <load:true, focus:true> -- loaded: complete active window: ([object ChromeWindow @ 0x10ff01f70 (native @ 0x109ffaa38)]) chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper [object Window @ 0x1119e7740 (native @ 0x114ff23c8)]]) about:blank desired window: ([object ChromeWindow @ 0x10ff01f70 (native @ 0x109ffaa38)]) chrome://browser/content/browser.xul child window: ([object XPCNativeWrapper [object Window @ 0x1119e7740 (native @ 0x114ff23c8)]]) about:blank docshell visible: true
(In reply to comment #0)
> http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1284059797.1284061653.5459.gz
> Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central debug test mochitest-other on
> 2010/09/09 12:16:37
> 
> TEST-START |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> Chrome file doesn't exist:
> /Users/cltbld/talos-slave/mozilla-central_snowleopard-debug_test-mochitest-other/build/mochitest/browser/browser/base/content/test/tabview/head.js

Does heads.js generate by the test framework?

> TEST-PASS |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Tab View is hidden
> TEST-PASS |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Tab View button exists
> TEST-PASS |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Tab View is hidden
> WARNING: Overflowed nscoord_MAX in conversion to nscoord: file
> ../../dist/include/nsCoord.h, line 359
> TEST-UNEXPECTED-FAIL |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Tab View is visible
> TEST-PASS |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Tab View is visible
> TEST-INFO |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Console message: tabview assert: must already be
> linkedTabItems__update([object
> XULElement])@chrome://browser/content/tabview.js:4548
> TabItems_heartbeat()@chrome://browser/content/tabview.js:4647
> TabItems_resumePainting()@chrome://browser/content/tabview.js:4685
> ()@chrome://browser/content/tabview.js:4382
> (-6)@chrome://browser/content/tabview.js:600
> 
> TEST-PASS |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Tab View is hidden
> WARNING: Overflowed nscoord_MAX in conversion to nscoord: file
> ../../dist/include/nsCoord.h, line 359
> WARNING: Overflowed nscoord_MAX in conversion to nscoord: file
> ../../dist/include/nsCoord.h, line 359
> WARNING: Overflowed nscoord_MAX in conversion to nscoord: file
> ../../dist/include/nsCoord.h, line 359
> TEST-PASS |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Tab View is visible
> TEST-PASS |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Tab View is hidden
> TEST-INFO |
> chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js
> | Test took 1.494s to complete
> 
> TEST-INFO | checking window state
> TEST-INFO | before wait for focus -- loaded: complete active window: ([object
> ChromeWindow @ 0x10ff01f70 (native @ 0x109ffaa38)])
> chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper
> [object Window @ 0x1119e7740 (native @ 0x114ff23c8)]]) about:blank desired
> window: ([object ChromeWindow @ 0x10ff01f70 (native @ 0x109ffaa38)])
> chrome://browser/content/browser.xul child window: ([object XPCNativeWrapper
> [object Window @ 0x1119e7740 (native @ 0x114ff23c8)]]) about:blank docshell
> visible: true
> TEST-INFO | already focused
> TEST-INFO | maybe run tests <load:true, focus:true> -- loaded: complete active
> window: ([object ChromeWindow @ 0x10ff01f70 (native @ 0x109ffaa38)])
> chrome://browser/content/browser.xul focused window: ([object XPCNativeWrapper
> [object Window @ 0x1119e7740 (native @ 0x114ff23c8)]]) about:blank desired
> window: ([object ChromeWindow @ 0x10ff01f70 (native @ 0x109ffaa38)])
> chrome://browser/content/browser.xul child window: ([object XPCNativeWrapper
> [object Window @ 0x1119e7740 (native @ 0x114ff23c8)]]) about:blank docshell
> visible: true
Attached patch v1 (obsolete) — Splinter Review
Pushed it to try and waiting for the results
Attachment #474392 - Flags: feedback?(ian)
Assignee: nobody → raymond
Passed try
Comment on attachment 474392 [details] [diff] [review]
v1

I'm not familiar with .doCommand, but if it does the trick, great! Any idea why .synthesizeMouse wasn't working?
Attachment #474392 - Flags: review?(dietrich)
Attachment #474392 - Flags: feedback?(ian)
Attachment #474392 - Flags: feedback+
Comment on attachment 474392 [details] [diff] [review]
v1

If we want to simulate a press on a button, the EventUtils.synthesizeMouse() isn't the best method to use because it causes some issues on some platforms.
Comment on attachment 474392 [details] [diff] [review]
v1

synthesized mouse clicks might fail if the app lost focus? regardless, this patch ensures execution, r=me.
Attachment #474392 - Flags: review?(dietrich) → review+
Attachment #474392 - Flags: approval2.0?
Should we be replacing our synthesizeMouse calls in our other tests as well? If so, please make a follow-up.
Comment on attachment 474392 [details] [diff] [review]
v1

Test fixes don't need approval.  Is this ready to land?
Attachment #474392 - Flags: approval2.0?
http://hg.mozilla.org/mozilla-central/rev/99c40db2f40e
Status: NEW → RESOLVED
Closed: 14 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 4.0b7
Looks like this is still happening so reopening
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Attached patch v2 (obsolete) — Splinter Review
Attachment #474392 - Attachment is obsolete: true
Attachment #475772 - Flags: feedback?(ian)
Comment on attachment 475772 [details] [diff] [review]
v2

Looks like the big change here is the executeSoon? I don't know enough to say whether this is good or bad. Seems worth a try...
Attachment #475772 - Flags: review?(dietrich)
Attachment #475772 - Flags: feedback?(ian)
Attachment #475772 - Flags: feedback+
Priority: -- → P1
Target Milestone: Firefox 4.0b7 → Future
Sorry, didn't mean to assign to future.
Target Milestone: Future → ---
Comment on attachment 475772 [details] [diff] [review]
v2

hrm, seems like there should be a deterministic event chain here. i guess r=me to land and see if it actually changes anything.

if it does, i think we should still try to track down exactly what is failing and where.
Attachment #475772 - Flags: review?(dietrich) → review+
Attached patch [checked-in] Patch for check-in (obsolete) — Splinter Review
Attachment #475772 - Attachment is obsolete: true
Comment on attachment 476766 [details] [diff] [review]
[checked-in] Patch for check-in

http://hg.mozilla.org/mozilla-central/rev/0dcf8c885e07
Attachment #476766 - Attachment description: Patch for check-in → [checked-in] Patch for check-in
Status: REOPENED → RESOLVED
Closed: 14 years ago14 years ago
Resolution: --- → FIXED
Re-opening as this has just occurred again, and it appears it wasn't certain the previous change would fix it.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
After looking into the log, I suspect the hide tabview is called after button.doCommand() but before onTabViewShown() so the TabView.isVisible() returns false.  I went through the test (browser_tabview_group.js) which runs before this test, however, couldn't find anything which might cause this.

Ian/mitcho/sean: if you have a chance, please have a look to see whether you can find something suspicious.

Chrome file doesn't exist: /Users/cltbld/talos-slave/tryserver_snowleopard-debug_test-mochitest-other/build/mochitest/browser/browser/base/content/test/tabview/head.js
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is hidden
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View button exists

// NOTE:  this shouldn't exist if the test runs correctly.
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is hidden
WARNING: Overflowed nscoord_MAX in conversion to nscoord: file ../../dist/include/nsCoord.h, line 359

TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is visible. Count: 0
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is visible. Count: 1
TEST-PASS | chrome://mochikit/content/browser/browser/base/content/test/tabview/browser_tabview_launch.js | Tab View is hidden
OS: Mac OS X → Windows 7
Assignee: raymond → ian
Blocks: 597043
Attached patch patch v1 (obsolete) — Splinter Review
I have no idea why it would be adding that extra hide in there. At any rate, we can make sure it doesn't do that, by not adding the hide handler until after the initial call, as I've done in this patch.

I've also updated some of the test messages to give us a little bit more diagnostic info, and I've removed the executeSoon as it didn't seem to make a difference. 

I also did a little re-org; I hope you don't mind.

Pushed to try: 9b2d7ed348e7
Attachment #476766 - Attachment is obsolete: true
Attachment #481095 - Flags: feedback?(raymond)
Comment on attachment 481095 [details] [diff] [review]
patch v1

Looks good.
Attachment #481095 - Flags: review?(dolske)
Attachment #481095 - Flags: feedback?(raymond)
Attachment #481095 - Flags: feedback+
Comment on attachment 481095 [details] [diff] [review]
patch v1

Switching the review to Dietrich, as he's already reviewed this bug a few times.
Attachment #481095 - Flags: review?(dolske) → review?(dietrich)
Attachment #481095 - Flags: review?(dietrich) → review+
Try was clean
Attachment #481095 - Flags: approval2.0?
Comment on attachment 481095 [details] [diff] [review]
patch v1

Test changes don't need approval.  Ship it! :)
Attachment #481095 - Flags: approval2.0?
Keywords: checkin-needed
http://hg.mozilla.org/mozilla-central/rev/7561c0da2362
Status: REOPENED → RESOLVED
Closed: 14 years ago14 years ago
Keywords: checkin-needed
Resolution: --- → FIXED
That try push was on top of http://hg.mozilla.org/mozilla-central/rev/5a41a70eb631 so it should have http://hg.mozilla.org/mozilla-central/rev/7561c0da2362 in it, though I'll wait for somewhere non-try to actually reopen.
Whiteboard: [orange] → [orange][qa-]
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Attached patch Patch v5, a new beginning (obsolete) — Splinter Review
Seems like the only possible explanation is that the deck doesn't update its selectedIndex until after the doCommand is finished; I've introduced a setTimeout to break the contention.
Attachment #481095 - Attachment is obsolete: true
Attachment #484822 - Flags: feedback?(raymond)
Comment on attachment 484822 [details] [diff] [review]
Patch v5, a new beginning

Looks like it would fix the issue.
Attachment #484822 - Flags: feedback?(raymond) → feedback+
Comment on attachment 484822 [details] [diff] [review]
Patch v5, a new beginning

Dietrich, I'm giving this to you for review, as you've reviewed the previous patches for this bug. Let me know if you feel you can't get to it.
Attachment #484822 - Flags: review?(dietrich)
Attached patch patch v6Splinter Review
Made the setTimeout keep trying, per Dietrich via IRC.
Attachment #484822 - Attachment is obsolete: true
Attachment #487446 - Flags: review?(dietrich)
Attachment #484822 - Flags: review?(dietrich)
Comment on attachment 487446 [details] [diff] [review]
patch v6

r=me, thanks!
Attachment #487446 - Flags: review?(dietrich) → review+
http://hg.mozilla.org/mozilla-central/rev/bcad241e5c22
Status: REOPENED → RESOLVED
Closed: 14 years ago14 years ago
Resolution: --- → FIXED
There was a merge problem with the last push. Re pushed: 

http://hg.mozilla.org/mozilla-central/rev/0951ef6b968f
Comment on attachment 487446 [details] [diff] [review]
patch v6

>diff --git a/browser/base/content/test/tabview/browser_tabview_launch.js b/browser/base/content/test/tabview/browser_tabview_launch.js
>--- a/browser/base/content/test/tabview/browser_tabview_launch.js
>+++ b/browser/base/content/test/tabview/browser_tabview_launch.js
>+      setTimeout(waitForSwitch, 10);

Ten milliseconds? Was that intended (asking out of curiosity).

>+  setTimeout(waitForSwitch, 1);

Common convention is to use setTimeout(fun, 0) for a simple (not time-specific) delay.
(In reply to comment #85)
> >+      setTimeout(waitForSwitch, 10);
> 
> Ten milliseconds? Was that intended (asking out of curiosity).

Yes. I figure if it didn't work right away, give the cpu a few extra cycles rather than checking immediately again.

> >+  setTimeout(waitForSwitch, 1);
> 
> Common convention is to use setTimeout(fun, 0) for a simple (not time-specific)
> delay.

I feel like I've had trouble with that in the past, but I'm not sure when or why.
Tinderbox machines tend to be __very__ slow, so 10 milliseconds is not really the same as on your dev machine. It might just create more overhead. IMHO, it should be a 100-200 value...
(In reply to comment #87)
> Tinderbox machines tend to be __very__ slow, so 10 milliseconds is not really
> the same as on your dev machine. It might just create more overhead. IMHO, it
> should be a 100-200 value...

Gotcha. Well, I really am expecting that the first setTimeout will cover it and that that second timeout is just a fallback, so hopefully it's not an issue. I'll definitely keep it in mind for next time.

Unless you think we should apply another patch?
(In reply to comment #86)
> (In reply to comment #85)
> > >+      setTimeout(waitForSwitch, 10);
> > 
> > Ten milliseconds? Was that intended (asking out of curiosity).
> 
> Yes. I figure if it didn't work right away, give the cpu a few extra cycles
> rather than checking immediately again.

This is wrong.  If setTimeout(0) doesn't work, you're doing something wrong.

Basically, setTimeout(foo, N) where N>0 is a recipe for intermittent orange.

> > >+  setTimeout(waitForSwitch, 1);
> > 
> > Common convention is to use setTimeout(fun, 0) for a simple (not time-specific)
> > delay.
> 
> I feel like I've had trouble with that in the past, but I'm not sure when or
> why.

More specifically, setTimeout(foo, 0) will run foo the next time we hit the event loop, which will be after other events currently in the queue have been processed.
(In reply to comment #89)
> > > >+      setTimeout(waitForSwitch, 10);
> > > 
> > > Ten milliseconds? Was that intended (asking out of curiosity).
> > 
> > Yes. I figure if it didn't work right away, give the cpu a few extra cycles
> > rather than checking immediately again.
> 
> This is wrong.  If setTimeout(0) doesn't work, you're doing something wrong.
>
> Basically, setTimeout(foo, N) where N>0 is a recipe for intermittent orange.

If you look at the code, this is part of a timeout loop where we wait for the status to change. I originally just had the 1 setTimeout (with 1ms), but dietrich suggested that it would be better to keep looping and polling the status. 
 
> > > >+  setTimeout(waitForSwitch, 1);
> > > 
> > > Common convention is to use setTimeout(fun, 0) for a simple (not time-specific)
> > > delay.
> > 
> > I feel like I've had trouble with that in the past, but I'm not sure when or
> > why.
> 
> More specifically, setTimeout(foo, 0) will run foo the next time we hit the
> event loop, which will be after other events currently in the queue have been
> processed.

Yeah, that was my understanding, but I found it didn't work that way somewhere... since I don't remember where, I guess I'll switch back to using 0.
Whiteboard: [orange][qa-] → [qa-]
Product: Firefox → Firefox Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: