Closed Bug 1020832 Opened 10 years ago Closed 10 years ago

Intermittent test_imestate.html | Test timed out.

Categories

(Core :: Widget, defect)

Product:
Core
Component:
Widget
Platform:
x86
macOS
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla33
Tracking Flags:
Tracking Status
firefox31 --- unaffected
firefox32 --- fixed
firefox33 --- fixed
firefox-esr24 --- unaffected

People

(Reporter: cbook, Assigned: masayuki)

References

(
URL
)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

Patch
2.64 KB, patch
enndeakin
: review+
lmandel
: approval-mozilla-aurora+
Details | Diff | Splinter Review 
Rev5 MacOSX Mountain Lion 10.8 mozilla-inbound opt test mochitest-other on 2014-06-04 23:16:30 PDT for push fe14647a422d

slave: talos-mtnlion-r5-041

https://tbpl.mozilla.org/php/getParsedLog.php?id=41093734&tree=Mozilla-Inbound



5174 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | Test timed out.
Can't help but notice that bug 1008772 landed shortly before this started failing.
Flags: needinfo?(masayuki)
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #4)
> Can't help but notice that bug 1008772 landed shortly before this started
> failing.

I don't think that it's the cause of this bug.

According to the log, the last test is finished. Then, window.close() is called in sub window which is http://mxr.mozilla.org/mozilla-central/source/widget/tests/window_imestate_iframes.html?force=1 . The call of window.close should cause unload event on its body element. And unload event handler should call SimpleTest.finish() of the opener.
http://mxr.mozilla.org/mozilla-central/source/widget/tests/window_imestate_iframes.html?force=1#15
http://mxr.mozilla.org/mozilla-central/source/widget/tests/window_imestate_iframes.html?force=1#51
http://mxr.mozilla.org/mozilla-central/source/widget/tests/test_imestate.html?force=1#1500

So, I suspect that unload event isn't run by window.close() sometimes.
Flags: needinfo?(masayuki)
If you want, I can try to bisect down to a specific regressing cset. But this bug is already showing high-enough frequency that it either needs a fix or backout ASAP IMO.
At the next green "oth" on Mac OS X 10.8, the log is like this:

> 01:18:15     INFO -  5071 INFO TEST-START | chrome://mochitests/content/chrome/widget/tests/test_imestate.html
> 01:18:19     INFO -  5072 INFO TEST-INFO | MEMORY STAT vsize after test: 4245614592
> 01:18:19     INFO -  5073 INFO TEST-INFO | MEMORY STAT residentFast after test: 889544704
> 01:18:19     INFO -  5074 INFO TEST-INFO | MEMORY STAT heapAllocated after test: 208766904
> 01:18:19     INFO -  5075 INFO TEST-END | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | finished in 3695ms
> 01:18:19     INFO -  NPP_Destroy
> 01:18:19     INFO -  5076 INFO TEST-START | chrome://mochitests/content/chrome/widget/tests/test_input_events_on_deactive_window.xul

However, the timed out logs are:

> 13:26:08     INFO -  5178 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | testOnEditorFlagChange: p[contenteditable=true]: when editor becomes read-write, IME is still disabled
> 13:26:08     INFO -  libpng warning: zero length keyword
> 13:26:08     INFO -  libpng warning: Empty language field in iTXt chunk
> 13:26:09     INFO -  TEST-INFO | screencapture: exit 0
> 13:26:09     INFO -  5179 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | Test timed out.
> 13:26:09     INFO -  5180 INFO TEST-INFO | MEMORY STAT vsize after test: 4240060416
> 13:26:09     INFO -  5181 INFO TEST-INFO | MEMORY STAT residentFast after test: 905211904
> 13:26:09     INFO -  5182 INFO TEST-INFO | MEMORY STAT heapAllocated after test: 161707144
> 13:26:09     INFO -  5183 INFO TEST-END | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | finished in 301510ms
> 13:26:09     INFO -  System JS : ERROR resource://app/modules/NetworkPrioritizer.jsm:88 - TypeError: aBrowser is undefined
> 13:26:10     INFO -  NPP_Destroy
> 13:26:10     INFO -  5184 INFO TEST-START | chrome://mochitests/content/chrome/widget/tests/test_input_events_on_deactive_window.xul

I don't know the "System JS : ERROR resource://app/modules/NetworkPrioritizer.jsm:88 - TypeError: aBrowser is undefined", though... But this always exists if it times out.
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #7)
> If you want, I can try to bisect down to a specific regressing cset. But
> this bug is already showing high-enough frequency that it either needs a fix
> or backout ASAP IMO.

Yeah, please. I have no idea which landing caused this... Even though, I checked the summaries of landings before fe14647a422d.
Very strange points:

* This is reproduced only on Mac OS X 10.8 opt.
* Capturing the screenshot at exiting from the test is always failed.
* The Sytem JS's error.
Yeah, very odd. I'm trying to understand what happens.
Although, tryserver is very clouded today...

According to this test build,
https://tbpl.mozilla.org/?tree=Try&usebuildbot=1&rev=7aeb3ba33763

> 00:18:34     INFO -  5174 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | testOnEditorFlagChange: p[contenteditable=true]: IME isn't enabled when the editor gets focus
> 00:18:34     INFO -  5175 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | testOnEditorFlagChange: p[contenteditable=true]: when editor becomes readonly, focus moved unexpectedly
> 00:18:34     INFO -  5176 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | testOnEditorFlagChange: p[contenteditable=true]: when editor becomes readonly, IME is still enabled
> 00:18:34     INFO -  5177 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | testOnEditorFlagChange: p[contenteditable=true]: when editor becomes read-write, focus moved unexpectedly
> 00:18:34     INFO -  5178 INFO TEST-PASS | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | testOnEditorFlagChange: p[contenteditable=true]: when editor becomes read-write, IME is still disabled
> 00:18:35     INFO -  libpng warning: zero length keyword
> 00:18:35     INFO -  libpng warning: Empty language field in iTXt chunk
> 00:18:35     INFO -  TEST-INFO | screencapture: exit 0
> 00:18:35     INFO -  5179 INFO TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | Test timed out.
> 00:18:35     INFO -  5180 INFO TEST-INFO | MEMORY STAT vsize after test: 4242042880
> 00:18:35     INFO -  5181 INFO TEST-INFO | MEMORY STAT residentFast after test: 908816384
> 00:18:35     INFO -  5182 INFO TEST-INFO | MEMORY STAT heapAllocated after test: 162433240
> 00:18:35     INFO -  5183 INFO TEST-END | chrome://mochitests/content/chrome/widget/tests/test_imestate.html | finished in 303486ms

Looks like that body's unload event handler isn't called.
Oh, I found this log.

> 00:14:32     INFO -  5076 INFO TEST-START | chrome://mochitests/content/chrome/widget/tests/test_imestate.html
> 00:14:35     INFO -  JavaScript error: chrome://browser/content/tabbrowser.xml, line 3036: Cc is not defined
> 00:14:35     INFO -  JavaScript error: chrome://browser/content/tabbrowser.xml, line 357: this.browsers[i] is undefined
> 00:14:35     INFO -  JavaScript error: chrome://browser/content/tabbrowser.xml, line 357: this.browsers[i] is undefined
> 00:14:35     INFO -  JavaScript error: chrome://browser/content/browser.js, line 13823: browser is undefined

When these errors occur, the test will time out.
Assignee: nobody → masayuki
Status: NEW → ASSIGNED
Keywords: regression
Comment on attachment 8435608 [details] [diff] [review]
Patch

Looks like that this fixes this bug. Although, why the Cc and Ci are *sometimes* not undefined...

https://tbpl.mozilla.org/?tree=Try&usebuildbot=1&rev=769c67f773be
Attachment #8435608 - Flags: review?(enndeakin)
Comment on attachment 8435608 [details] [diff] [review]
Patch

Looks like Cc isn't defined right away in browser.js but gets defined later in some loaded-in script. So the timing could affect when this happens.
Attachment #8435608 - Flags: review?(enndeakin) → review+
https://hg.mozilla.org/mozilla-central/rev/29e439768635
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla33
Comment on attachment 8435608 [details] [diff] [review]
Patch

[Approval Request Comment]
Bug caused by (feature/regressing bug #): bug 1008772
User impact if declined: This patch indicates that tabbrowser sometimes fails to initialize its member. Therefore, when this bug is reproduced on real environment, a lot of feature of tab browsing is dead.
Testing completed (on m-c, etc.): Landed on m-c.
Risk to taking this patch (and alternatives if risky): No except this patch has simple mistake. This patch just stops using global object, Cc and Ci at constructor and destructor since they are sometimes not available. 
String or IDL/UUID changes made by this patch: No.
Attachment #8435608 - Flags: approval-mozilla-aurora?
Comment on attachment 8435608 [details] [diff] [review]
Patch

Aurora approval granted.
Attachment #8435608 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: