Open Bug 1208197 Opened 8 years ago Updated 11 months ago

Intermittent test_bug533845.xhtml,test_bug533845.xul | Test timed out.

Categories

(Core :: Layout, defect, P3)

Product:
Core
Component:
Layout
Type:
defect

Tracking

()

Status:
REOPENED
Tracking Flags:
Tracking Status
firefox55 --- disabled
firefox56 --- disabled

People

(Reporter: KWierso, Unassigned)

Details

(Keywords: intermittent-failure, leave-open, Whiteboard: [stockwell disabled])

Attachments

(2 files)

Modify how we open/close the popup for this test to use addEventListener()
1.64 KB, patch
smaug
: review+
Details | Diff | Splinter Review
disable_test_bug533845.patch
841 bytes, patch
ahal
: review+
Details | Diff | Splinter Review 
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
This test is normally very fast, completing in under 100 ms. When it fails, there is no activity for several minutes:

[task 2017-04-15T13:23:30.043458Z] 13:23:30     INFO - TEST-START | layout/base/tests/chrome/test_bug533845.xul
[task 2017-04-15T13:28:53.130164Z] 13:28:53     INFO - TEST-INFO | started process screentopng
[task 2017-04-15T13:28:53.451285Z] 13:28:53     INFO - TEST-INFO | screentopng: exit 0
[task 2017-04-15T13:28:53.451370Z] 13:28:53     INFO - TEST-UNEXPECTED-FAIL | layout/base/tests/chrome/test_bug533845.xul | Test timed out. 
[task 2017-04-15T13:28:53.451446Z] 13:28:53     INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:121:7
[task 2017-04-15T13:28:53.451517Z] 13:28:53     INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:142:7
[task 2017-04-15T13:28:53.451581Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.451646Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.451708Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.451771Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.451834Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.451898Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.451964Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.452034Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.452103Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.452171Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.452283Z] 13:28:53     INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:163:5
[task 2017-04-15T13:28:53.452342Z] 13:28:53     INFO - TestRunner.runTests@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:380:5
[task 2017-04-15T13:28:53.452394Z] 13:28:53     INFO - RunSet.runtests@chrome://mochikit/content/tests/SimpleTest/setup.js:194:3
[task 2017-04-15T13:28:53.452450Z] 13:28:53     INFO - RunSet.runall@chrome://mochikit/content/tests/SimpleTest/setup.js:173:5
[task 2017-04-15T13:28:53.452506Z] 13:28:53     INFO - hookupTests@chrome://mochikit/content/tests/SimpleTest/setup.js:266:5
[task 2017-04-15T13:28:53.452561Z] 13:28:53     INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5
[task 2017-04-15T13:28:53.452624Z] 13:28:53     INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11
[task 2017-04-15T13:28:53.452687Z] 13:28:53     INFO - EventHandlerNonNull*getTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3
[task 2017-04-15T13:28:53.452740Z] 13:28:53     INFO - hookup@chrome://mochikit/content/tests/SimpleTest/setup.js:246:5
[task 2017-04-15T13:28:53.452792Z] 13:28:53     INFO - linkAndHookup@chrome://mochikit/content/harness.xul:59:3
[task 2017-04-15T13:28:53.452846Z] 13:28:53     INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5
[task 2017-04-15T13:28:53.452927Z] 13:28:53     INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11
[task 2017-04-15T13:28:53.452994Z] 13:28:53     INFO - EventHandlerNonNull*getTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3
[task 2017-04-15T13:28:53.453048Z] 13:28:53     INFO - getTestList@chrome://mochikit/content/chrome-harness.js:260:3
[task 2017-04-15T13:28:53.453097Z] 13:28:53     INFO - loadTests@chrome://mochikit/content/harness.xul:38:3
[task 2017-04-15T13:28:53.453180Z] 13:28:53     INFO - EventListener.handleEvent*@chrome://mochikit/content/harness.xul:62:5
[task 2017-04-15T13:28:54.133759Z] 13:28:54     INFO - GECKO(1568) | MEMORY STAT | vsize 2109MB | residentFast 200MB | heapAllocated 81MB
[task 2017-04-15T13:28:54.135956Z] 13:28:54     INFO - TEST-OK | layout/base/tests/chrome/test_bug533845.xul | took 324091ms
The test seems to run reliably on all platforms except Linux. On Linux, it's a medium-frequency intermittent.
Whiteboard: [stockwell needswork]
this picked up may22, then may24- primarily failing on linux32 opt and linux64 opt/pgo.

here is a recent failure log:
https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=103146649&lineNumber=2427

and related screenshot:
https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=103146649&lineNumber=2427

unfortunately the log doesn't have anything in it other than:
task 2017-05-30T20:08:29.222457Z] 20:08:29     INFO - TEST-OK | layout/base/tests/chrome/test_bug514660.xul | took 55ms
[task 2017-05-30T20:08:29.250378Z] 20:08:29     INFO - TEST-START | layout/base/tests/chrome/test_bug533845.xul
[task 2017-05-30T20:13:52.007100Z] 20:13:52     INFO - TEST-INFO | started process screentopng
[task 2017-05-30T20:13:52.334210Z] 20:13:52     INFO - TEST-INFO | screentopng: exit 0
[task 2017-05-30T20:13:52.334296Z] 20:13:52     INFO - TEST-UNEXPECTED-FAIL | layout/base/tests/chrome/test_bug533845.xul | Test timed out. 


possibly we are not showing the popup?

:jet, can you help find someone to look at this issue as it is occurring frequently enough.
Flags: needinfo?(bugs)
Use openPopup() and addEventListener() just like test_bug467442.xul to prevent raciness.
Attachment #8873344 - Flags: review?(bugs)
Attachment #8873344 - Flags: review?(bugs) → review+
Pushed by jvillegas@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/c738c30dc6a2
Use addEventListener() in test_bug533845.xul to prevent raciness. r=smaug
Flags: needinfo?(bugs)
https://hg.mozilla.org/mozilla-central/rev/c738c30dc6a2
Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox55: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
(In reply to Sebastian Hengst [:aryx][:archaeopteryx] (needinfo on intermittent or backout) from comment #65)
> This still hits the test, e.g. twice in
> https://treeherder.mozilla.org/#/jobs?repo=mozilla-
> inbound&revision=bb37ef22d35ca7d9c5c77805a1aceb62e15773b1&filter-
> resultStatus=testfailed&filter-resultStatus=busted&filter-
> resultStatus=exception&filter-resultStatus=retry&filter-
> resultStatus=usercancel&filter-resultStatus=runnable

Ugh, OK. I rewrote this test using JS from layout/xul/test/test_bug467442.xul but now I'm not sure if we're also getting intermittent failures on that test. Is there a way to tell the failure history on that test? I'd expect that we're seeing similar Linux failures on that one as well.
Flags: needinfo?(aryx.bugmail)
(In reply to Jet Villegas (:jet) from comment #68)
> Ugh, OK. I rewrote this test using JS from
> layout/xul/test/test_bug467442.xul but now I'm not sure if we're also
> getting intermittent failures on that test. Is there a way to tell the
> failure history on that test? I'd expect that we're seeing similar Linux
> failures on that one as well.

Bugzilla doesn't find "467442" in any bug summary, so there is no bug to track intermittent failures of that test, hence it doesn't seem to fail.
Flags: needinfo?(aryx.bugmail)
:jet, thanks for looking into this bug and pushing a fix.  I would think your new code would be more stable than before.  Unfortunately it isn't which is frustrating :(

I looked over the new test case and noticed we have:
panel.openPopup();

whereas the example has:
panel.openPopup(anchor, "after_start", 0, 0, false, false);


I would think given that the screenshot shows no popup, that we are not seeing the popup open up and there are issues there with some timing?

Likewise there could be issues with the sendMouseEvent() or missing the popupHidden.  Would it be randomly possible that we receive the popupshown for some other action in the browser and we never execute the code?
this is happening 20%+ of the time, lets disable this on linux*/opt for now until there is more time to work on this.
Attachment #8877966 - Flags: review?(ahalberstadt)
Comment on attachment 8877966 [details] [diff] [review]
disable_test_bug533845.patch

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

nit: whitespace
Attachment #8877966 - Flags: review?(ahalberstadt) → review+
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/a8600c9c47ec
temporarily disable test_bug533845.xul. r=ahal
Keywords: leave-open
Whiteboard: [stockwell needswork] → [stockwell disabled]
Target Milestone: mozilla55 → ---
I could reproduce this phenomenon on local vm(linux 32 opt build).

In my investigation, nsXULPopupManager::Rollup() call the nsXULPopupManager::HidePopup() immediately after calling the nsXULPopupManager::ShowPopup().[1]

[1] http://searchfox.org/mozilla-central/rev/6482c8a5fa5c7446e82ef187d1a1faff49e3379e/widget/gtk/nsWindow.cpp#2896

This function called by OnContainerFocusOutEvent(This event occurred from focus_out_event on GTK API), but I'm not sure that why this event triggered sometimes.
(Usually this event doesn't triggered. If this event occurred, this test should be fail.)
Karlt
I think that GTK will fire this focus_out_event if other xul component get the focus when opening popup. Is my understand correct?
If you have filed the similar bug already, could you please tell me those?
Flags: needinfo?(karlt)
(In reply to Mantaroh Yoshinaga[:mantaroh] from comment #88)
> I think that GTK will fire this focus_out_event if other xul component get
> the focus when opening popup. Is my understand correct?

If another toplevel window becomes the active window, then focus-out-event
will be triggered in the previously active toplevel window.

When focus moves between elements of the same toplevel window, there is no
change in the active window, and no focus-out-event.

In the test here, focus moves to an element in a popup window.  The popup
window should not become the active window, but its owning toplevel window
should remain the active window and no focus-out-event should be dispatched.

https://bugzilla.mozilla.org/show_bug.cgi?id=1236153#c5 contains a program
that can monitor the focus change events (and others) on the system.

NSPR_LOG_MODULES=Widget:5,WidgetFocus:5 provides logging in nsWindow.
Flags: needinfo?(karlt)
Thanks, and sorry for a too late reply.

I looked into this phenomenon.
This phenomenon will occur on only XVFB environment(which same to try environment), and it looks like other window gets focus.
If I don't use XVFB, we can't reproduce this bug.

After I updated xorg-server to 2:1.19.3-1ubuntu1.1, this I can't reproduce this phenomenon.
(In reply to Mantaroh Yoshinaga[:mantaroh] from comment #90)
> Thanks, and sorry for a too late reply.
> 
> I looked into this phenomenon.
> This phenomenon will occur on only XVFB environment(which same to try
> environment), and it looks like other window gets focus.
> If I don't use XVFB, we can't reproduce this bug.
> 
> After I updated xorg-server to 2:1.19.3-1ubuntu1.1, this I can't reproduce
> this phenomenon.

This orange doesn't appear last 1 month, So I'll re-investigate when this orange appears again frequently.
Flags: needinfo?(bugs)
Summary: Intermittent test_bug533845.xul | Test timed out. → Intermittent test_bug533845.xhtml,test_bug533845.xul | Test timed out.
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.