Intermittent test_bug533845.xul | Test timed out.

REOPENED
Unassigned

Status

()

defect
P3
normal
REOPENED
4 years ago
a year ago

People

(Reporter: KWierso, Unassigned)

Tracking

({intermittent-failure, leave-open})

unspecified
Points:
---

Firefox Tracking Flags

(firefox55 disabled, firefox56 disabled)

Details

(Whiteboard: [stockwell disabled])

Attachments

(2 attachments)

Reporter

Description

4 years ago
No description provided.
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)

Comment 38

3 years ago
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
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.
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
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)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Use openPopup() and addEventListener() just like test_bug467442.xul to prevent raciness.
Attachment #8873344 - Flags: review?(bugs)
Attachment #8873344 - Flags: review?(bugs) → review+
Comment hidden (Intermittent Failures Robot)

Comment 63

2 years ago
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)

Comment 64

2 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/c738c30dc6a2
Status: NEW → RESOLVED
Last Resolved: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla55
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
(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)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
(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?
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
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+

Comment 80

2 years ago
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]
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Target Milestone: mozilla55 → ---
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
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.
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Flags: needinfo?(bugs)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
Comment hidden (Intermittent Failures Robot)
You need to log in before you can comment on or make changes to this bug.