Filed by: philringnalda [at] gmail.com https://treeherder.mozilla.org/logviewer.html#?job_id=78101622&repo=mozilla-inbound https://queue.taskcluster.net/v1/task/XhXNw9nbSm23_3-o0Jt80Q/runs/0/artifacts/public/logs/live_backing.log

this has picked up in frequency in the last week, 33 failures since last friday :( Primarily on linux64 debug/asan. Around March 13th you can see the pickup: https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1340413&startday=2017-03-10&endday=2017-03-17&tree=all doing a few retriggers to help see if there was a change that triggered this to be more frequent: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&filter-searchStr=linux%20debug%20mochitest-chrome-3%20x64&tochange=950180909fd0e5031a04fcd4cb8f94ff4be72ae6&fromchange=a57d843357e2d93d43e2508de1793f63b355fab9&selectedJob=83437036 I will follow up shortly

shortly is a whole day later! I ended up doing a few round of retriggers, nothing is standing out as a culprit (orange job == a few different regressions, not always this regression). the first instance is found here: https://hg.mozilla.org/integration/mozilla-inbound/rev/2b52802899ae6b4d14481481e0ea37664c48a7d5 I am not sure if that is a root cause since this doesn't happen much, but I have many retriggers on a few revisions prior with no instances. here is data from the log [0]: [task 2017-03-17T14:07:27.272930Z] 14:07:27 INFO - TEST-START | toolkit/content/tests/chrome/test_panel.xul [task 2017-03-17T14:07:27.857787Z] 14:07:27 INFO - GECKO(5499) | MEMORY STAT | vsize 20973989MB | residentFast 1473MB [task 2017-03-17T14:07:27.875838Z] 14:07:27 INFO - TEST-OK | toolkit/content/tests/chrome/test_panel.xul | took 603ms [task 2017-03-17T14:07:28.943875Z] 14:07:28 INFO - TEST-START | toolkit/content/tests/chrome/test_panel_anchoradjust.xul [task 2017-03-17T14:12:34.788378Z] 14:12:34 INFO - TEST-INFO | started process screentopng [task 2017-03-17T14:12:35.135024Z] 14:12:35 INFO - TEST-INFO | screentopng: exit 0 [task 2017-03-17T14:12:35.135103Z] 14:12:35 INFO - Buffered messages logged at 14:07:29 [task 2017-03-17T14:12:35.135142Z] 14:12:35 INFO - must wait for load [task 2017-03-17T14:12:35.135177Z] 14:12:35 INFO - must wait for focus [task 2017-03-17T14:12:35.135231Z] 14:12:35 INFO - TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | anchor moved x [task 2017-03-17T14:12:35.135294Z] 14:12:35 INFO - TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | anchor moved y [task 2017-03-17T14:12:35.135352Z] 14:12:35 INFO - TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | new anchor x [task 2017-03-17T14:12:35.135412Z] 14:12:35 INFO - TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | new anchor y [task 2017-03-17T14:12:35.135476Z] 14:12:35 INFO - TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | new anchor with offset x [task 2017-03-17T14:12:35.135537Z] 14:12:35 INFO - TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | new anchor with offset y [task 2017-03-17T14:12:35.135578Z] 14:12:35 INFO - Buffered messages finished [task 2017-03-17T14:12:35.136762Z] 14:12:35 INFO - TEST-UNEXPECTED-FAIL | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | Test timed out. [task 2017-03-17T14:12:35.137369Z] 14:12:35 INFO - reportError@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:120:7 [task 2017-03-17T14:12:35.137560Z] 14:12:35 INFO - TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:141:7 [task 2017-03-17T14:12:35.138133Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.138770Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.138921Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.139509Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.139656Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.140299Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.140880Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.141064Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.141684Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.142286Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.142448Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.143024Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.143199Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.143787Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.144369Z] 14:12:35 INFO - setTimeout handler*TestRunner._checkForHangs@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:162:5 [task 2017-03-17T14:12:35.144510Z] 14:12:35 INFO - TestRunner.runTests@chrome://mochikit/content/tests/SimpleTest/TestRunner.js:379:5 [task 2017-03-17T14:12:35.145108Z] 14:12:35 INFO - RunSet.runtests@chrome://mochikit/content/tests/SimpleTest/setup.js:190:3 [task 2017-03-17T14:12:35.145269Z] 14:12:35 INFO - RunSet.runall@chrome://mochikit/content/tests/SimpleTest/setup.js:169:5 [task 2017-03-17T14:12:35.145399Z] 14:12:35 INFO - hookupTests@chrome://mochikit/content/tests/SimpleTest/setup.js:262:5 [task 2017-03-17T14:12:35.145497Z] 14:12:35 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5 [task 2017-03-17T14:12:35.145642Z] 14:12:35 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11 [task 2017-03-17T14:12:35.145815Z] 14:12:35 INFO - EventHandlerNonNull*getTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3 [task 2017-03-17T14:12:35.145912Z] 14:12:35 INFO - hookup@chrome://mochikit/content/tests/SimpleTest/setup.js:242:5 [task 2017-03-17T14:12:35.145973Z] 14:12:35 INFO - linkAndHookup@chrome://mochikit/content/harness.xul:59:3 [task 2017-03-17T14:12:35.146064Z] 14:12:35 INFO - parseTestManifest@chrome://mochikit/content/manifestLibrary.js:38:5 [task 2017-03-17T14:12:35.146126Z] 14:12:35 INFO - getTestManifest/req.onload@chrome://mochikit/content/manifestLibrary.js:49:11 [task 2017-03-17T14:12:35.146294Z] 14:12:35 INFO - EventHandlerNonNull*getTestManifest@chrome://mochikit/content/manifestLibrary.js:45:3 [task 2017-03-17T14:12:35.146353Z] 14:12:35 INFO - getTestList@chrome://mochikit/content/chrome-harness.js:260:3 [task 2017-03-17T14:12:35.146443Z] 14:12:35 INFO - loadTests@chrome://mochikit/content/harness.xul:38:3 [task 2017-03-17T14:12:35.146502Z] 14:12:35 INFO - EventListener.handleEvent*@chrome://mochikit/content/harness.xul:62:5 [task 2017-03-17T14:12:35.795599Z] 14:12:35 INFO - GECKO(5499) | MEMORY STAT | vsize 20974174MB | residentFast 1607MB [task 2017-03-17T14:12:35.797829Z] 14:12:35 INFO - TEST-OK | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | took 306854ms [task 2017-03-17T14:12:35.932355Z] 14:12:35 INFO - TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | no follow anchor x [task 2017-03-17T14:12:35.932446Z] 14:12:35 INFO - TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | no follow anchor y [task 2017-03-17T14:12:35.932498Z] 14:12:35 ERROR - [SimpleTest.finish()] this test already called finish! [task 2017-03-17T14:12:35.932577Z] 14:12:35 INFO - TEST-UNEXPECTED-ERROR | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | called finish() multiple times [task 2017-03-17T14:12:35.932615Z] 14:12:35 INFO - TEST-INFO and the related screenshot: https://public-artifacts.taskcluster.net/alLNdL6JTQasYIDWzIFz-Q/0/public/test_info//mozilla-test-fail-screenshot_lYeEHW.png this is the last test output message we get: TEST-PASS | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | new anchor with offset y which aligns with the code here: https://dxr.mozilla.org/mozilla-central/source/toolkit/content/tests/chrome/window_panel_anchoradjust.xul?q=path%3Awindow_panel_anchoradjust.xul&redirect_type=single#100 typically this test takes <1s: TEST-OK | toolkit/content/tests/chrome/test_panel_anchoradjust.xul | took 596ms but we are timing out after 5 minutes :( I would like to sanity check where we are timing out and if the changeset from bug 1346426 seems possible to trigger this. [0] https://public-artifacts.taskcluster.net/alLNdL6JTQasYIDWzIFz-Q/0/public/logs/live_backing.log

This test was added in bug 1109868; the first failure recorded here happened on the same day. Hopefully Neil can make this test more reliable.

This test is showing two popups, the second one anchored on an element in the first one. The first popup is being hidden and the expectation is that the second popup will get hidden due to the first one not being open anymore. Testing shows that nsXULPopupManager::UpdatePopupPositions isn't being called on Linux when the test fails. It is fairly easy to workaround in most cases by calling UpdatePopupPositions manually whenever a popup is hidden, and I'll probably add something that does this to fix this test, but it's possible that there is some underlying bug. I didn't investigate whether nsRefreshDriver::Tick is actually called when it fails, but the part where UpdatePopupPositions is not. Timothy, does this sound like a real bug?

(In reply to Neil Deakin from comment #8) > This test is showing two popups, the second one anchored on an element in > the first one. The first popup is being hidden and the expectation is that > the second popup will get hidden due to the first one not being open anymore. > > Testing shows that nsXULPopupManager::UpdatePopupPositions isn't being > called on Linux when the test fails. It is fairly easy to workaround in most > cases by calling UpdatePopupPositions manually whenever a popup is hidden, > and I'll probably add something that does this to fix this test, but it's > possible that there is some underlying bug. > > I didn't investigate whether nsRefreshDriver::Tick is actually called when > it fails, but the part where UpdatePopupPositions is not. Timothy, does this > sound like a real bug? No. I don't think it'll tick if there is nothing wanting a tick. So your proposed fix sounds good to me.

checking in here, this test is still failing at ~50 failures/week, it sounds like we have an idea of how to fix this, would it be realistic to expect that in the next week (by the end of the month)?

Pushed by neil@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/16fc5defd30f check for anchor changes that affect popup positions and visibility whenever a popup is closed, r=tn

Please request Aurora/Beta approval on this when you get a chance.

Comment on attachment 8851549 [details] update the popup anchors whenever a popup is closed Approval Request Comment [Feature/Bug causing the regression]: minor fix causing intermittent test failure [User impact if declined]: none [Is this code covered by automated tests?]: fixes test [Has the fix been verified in Nightly?]: [Needs manual test from QE? If yes, steps to reproduce]: no [List of other uplifts needed for the feature/fix]: none, followup for 1109868 [Is the change risky?]: no [Why is the change risky/not risky?]: it just manually calls a function that normally gets called every paint, but doesn't in one edge case on linux [String changes made/needed]: no

Comment on attachment 8851549 [details] update the popup anchors whenever a popup is closed Fix for regression from 53, let's uplift to beta.

This is still happening :(

On Ubuntu 16: https://treeherder.mozilla.org/#/jobs?repo=try&revision=0c041857b1b070070326b1cd71e1abdbbc3f340e On Ubuntu 12: https://treeherder.mozilla.org/#/jobs?repo=try&revision=bede219f13807f8deb987fee540b718cbcab9d01

Didn't bug 1369488 fix this?

the one instance was on the 15th, the same day the patch landed, I assume this was a failure that occurred prior to the fix.

Comment on attachment 8878901 [details] Bug 1340413 - Disable test_panel_anchoradjust.xul for linux. https://reviewboard.mozilla.org/r/150146/#review155064

Pushed by jmaher@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/6e371bef11ca Disable test_panel_anchoradjust.xul for linux. r=jmaher

marking as leave open since we are disabling a test in order to move forward in porting tests to ubuntu 16.

Why are we disabling it if it's fixed?

it is not fixed on ubuntu 16.04, only for the 12.04 use case

Where is a treeherder link to see the failure?

Here's the latest one that we were using and it didn't have the changes from bug 1369488, it just missed them: https://treeherder.mozilla.org/#/jobs?repo=try&revision=c74afcf988a46f76c1360625042384013e74d0c7 I'm running a push to try with the update now to be sure that it's no longer failing on Ubuntu 16 also (Note: it's possible for there to be other errors in this one as their patches may not have landed yet but this doesn't stop test_panel_anchoradjust.xul from failing if it still does) : https://treeherder.mozilla.org/#/jobs?repo=try&revision=096b8ae7384abbe34bc567809213c59a5c9ad584

(In reply to Greg Mierzwinski [:gmierz] from comment #43) > Here's the latest one that we were using and it didn't have the changes from > bug 1369488, it just missed them: > https://treeherder.mozilla.org/#/ > jobs?repo=try&revision=c74afcf988a46f76c1360625042384013e74d0c7 > > I'm running a push to try with the update now to be sure that it's no longer > failing on Ubuntu 16 also (Note: it's possible for there to be other errors > in this one as their patches may not have landed yet but this doesn't stop > test_panel_anchoradjust.xul from failing if it still does) : > https://treeherder.mozilla.org/#/ > jobs?repo=try&revision=096b8ae7384abbe34bc567809213c59a5c9ad584 Thanks. Looks like test_panel_anchoradjust.xul doesn't fail in that push. So we should be able to re-enable this test.

Ok, I've pushed a patch to enable this test in bug 1374627.

Greg, thanks for looking into this and :tnikkel, thanks for pointing out the oversight!

This test is enabled so is there anything else to do here?

oh, I think we are good!

Removing leave-open keyword from resolved bugs, per :sylvestre.