Closed Bug 569237 Opened 14 years ago Closed 14 years ago

Intermittent timeout in test_mozPaintCount.html

Categories

(Core :: Layout, defect)

Product:
Core
Component:
Layout
Platform:
x86
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED DUPLICATE of bug 585286

People

(Reporter: ehsan.akhgari, Assigned: karlt)

References

Details

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

Attachments

(5 files, 1 obsolete file)

Add some debugging information
1.03 KB, patch
Details | Diff | Splinter Review
screenshot of energy settings
724.25 KB, image/png
Details
screenshot of initial state (terminal window for running buildbot on front)
1.13 MB, image/png
Details
window info
14.09 KB, text/plain
Details
screenshot: black screen
3.81 KB, image/png
Details 
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275321900.1275323693.6179.gz
Rev3 Fedora 12 mozilla-central opt test mochitests-4/5 on 2010/05/31 09:05:00
Trying to see what's going on here.
Attachment #449213 - Flags: review?(roc)
Comment on attachment 449213 [details] [diff] [review]
Add some debugging information

Landed as http://hg.mozilla.org/mozilla-central/rev/9b29864cabd1.

dholbert reminded me that we don't print the values passed to is if the test is successful, so I moved them to the log message itself.
Attachment #449213 - Flags: review?(roc)
The exact thing that I described in bug 569238 comment 29 is happening here as well.  This explains why these two failures *always* occur with each other.
See Also: → 569238
Is it possible the window containing the test is covered by another window?
(In reply to comment #28)
> Is it possible the window containing the test is covered by another window?

I think it is, yes.  I've seen windows which have the focus being covered by other windows in Linux...  And this failure only happens on Linux.
Armen, is there any way to take a screen capture of the Linux unit test machine runs on which this test is failing?
I don't know how I could take a screen shot of the right thing.

Do you guys want access to a machine to try to reproduce it?
I'm not sure ... Ehsan, Karl, do you know of any way we can try to force the window to come to the front at the start of the test?
(In reply to comment #36)
> gtk_window_set_keep_above, maybe?
> <http://library.gnome.org/devel/gtk/unstable/GtkWindow.html#gtk-window-set-keep-above>

Neil, is this something which we can do as part of SetFocus on gtk, somehow?
Also, roc, can we use the MozAfterPaint event to actually make sure in the plugin area was in fact painted?
I just verified this theory by starting layout/base mochitests, and dragging the test window to the bottom edge so that the content was invisible.  test_flush_on_paint.html and test_paintCount.html both timed out every time.
(In reply to comment #36)
> gtk_window_set_keep_above, maybe?
> <http://library.gnome.org/devel/gtk/unstable/GtkWindow.html#gtk-window-set-keep-above>

I assume that requests that the window is kept above permanently (even when it does not have focus).

We wouldn't want that for the web browser, though possibly an option for a special mochitest window.
OS: Mac OS X → Linux
(In reply to comment #35)
> do you know of any way we can try to force the
> window to come to the front at the start of the test?

We can lie about the time of user interaction that caused the window to be opened.

But if that was the problem then I would expect focus problems also.

What other windows are shown on these machines?
I assumed there would be no other windows, and so there would be no need to be in front of anything.

If this problem is caused by another window, then it could be tooltip or a window from a previous test.
If these tests are run on a system using a virtual screen, then expose events may not get received.  Are these test run under Xvfb?  Can I see how the X server is set up?
Bug 569238 started at the same time as this, and bug 557456 and bug 563663 also started failing more regularly with a new failure mode a similar time.
The cause is almost certainly the same.

How can we find out whether anything might have changed in the test environment around this time?

(I considered bug 562574 as a possible cause, but I'm not seeing those assertions/warnings in the logs.)
Blocks: 569238, 557456, 563663
Lack of painting would also cause bug 569425 to happen as image maps only setup on paint.
(In reply to comment #43)
> Bug 569238 started at the same time as this, and bug 557456 and bug 563663 also
> started failing more regularly with a new failure mode a similar time.
> The cause is almost certainly the same.
> 
> How can we find out whether anything might have changed in the test environment
> around this time?

Maybe someone from releng can answer this?
Blocks: 569425
(In reply to comment #41)
> If this problem is caused by another window, then it could be tooltip ...

Actually, the invalidation management is not that clever.  I think only bug 563663 could be caused by a tooltip (because it uses a small windowed plugin), as the whole (child) window would need to be obscured (or minimized) to prevent invalidations from causing expose events.
Could there be a screensaver operating on the test machines?
(In reply to comment #47)
> Could there be a screensaver operating on the test machines?

Possibly!  I recently saw some focus errors on mac because of screensaver problems.  Armen, do we have screensaver disabled on our linux unit test machines?
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276143548.1276148173.28538.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitests-4/5 on 2010/06/09 21:19:08

s: talos-r3-fed64-043
10888 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_flush_on_paint.html | Test timed out.
39546 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_mozPaintCount.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276230992.1276232917.3066.gz
Rev3 Fedora 12 mozilla-central opt test mochitests-4/5 on 2010/06/10 21:36:32

s: talos-r3-fed-035
10929 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_flush_on_paint.html | Test timed out.
39558 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_mozPaintCount.html | Test timed out.
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276232643.1276236305.13424.gz
Rev3 Fedora 12 mozilla-central debug test mochitests-4/5 on 2010/06/10 22:04:03

s: talos-r3-fed-038
10567 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_flush_on_paint.html | Test timed out.
37865 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_mozPaintCount.html | Test timed out.
(In reply to comment #34)
> Do you guys want access to a machine to try to reproduce it?

Armen, this might be worth a try.
I'm in LDAP as ktomlinson @ mozilla . com.
If you could point me at the toplevel scripts that get run, please,
that would also be helpful.
(In reply to comment #48)
> (In reply to comment #47)
> > Could there be a screensaver operating on the test machines?
> 
> Possibly!  I recently saw some focus errors on mac because of screensaver
> problems.  Armen, do we have screensaver disabled on our linux unit test
> machines?

The screen saver is disabled on the Fedora machines https://wiki.mozilla.org/ReferencePlatforms/Test/FedoraLinux#Preferences since the ref machine (I double checked and I will attach screen shots).

(In reply to comment #73)
> (In reply to comment #34)
> > Do you guys want access to a machine to try to reproduce it?
> 
> Armen, this might be worth a try.
> I'm in LDAP as ktomlinson @ mozilla . com.
> If you could point me at the toplevel scripts that get run, please,
> that would also be helpful.

Email sent.
Since we're using a regular desktop OS, it would be possible for another window to pop up without us knowing, right?  An update dialog, some kind of alert/alarm window, etc?
If such thing is happening the machine I gave you access to should hit this at some point.

FYI in the ref page it is listed that updates are disabled.
I wonder why most reports are on 64-bit systems.
Blocks: 572415
David, do you think you could tolerate taking this change until we get some data?
That will probably be about a day (or a weekend).
(Squeezing this in here is simpler than adding another filter to automation.py, particularly given my inexperience in python.)
Assignee: nobody → karlt
Attachment #451810 - Flags: feedback?
Comment on attachment 451810 [details] [diff] [review]
dump some window state on mochitest time out

I assume that Karl wanted to set the requestee here.
Attachment #451810 - Flags: feedback? → feedback?(dbaron)
Blocks: 569974
Comment on attachment 451810 [details] [diff] [review]
dump some window state on mochitest time out

If this is temporary it's fine with me, but probably better if it doesn't stay in too long.
Attachment #451810 - Flags: feedback?(dbaron) → feedback+
Comment on attachment 451810 [details] [diff] [review]
dump some window state on mochitest time out

http://hg.mozilla.org/mozilla-central/rev/b8ddc4e35f65
Attached file window info — 
From the log in comment 120.

The only managed windows above the mochitest window are "Bottom Panel" and
"Top Panel", and they are not obscuring the mochitest window.

The unmanaged windows above in the stacking order (but possibly unmapped) all look too small to obscure the mochitest window.

Backed out the logging commands:
http://hg.mozilla.org/mozilla-central/rev/b1ca746dce5a

It doesn't look like anything is obscuring the mochitest window.
Attachment #451810 - Attachment is obsolete: true
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1278637075.1278641453.29437.gz
Rev3 Fedora 12 mozilla-central debug test mochitests-4/5 on 2010/07/08 17:57:55

s: talos-r3-fed-023
10480 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_flush_on_paint.html | Test timed out.
37280 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_mozPaintCount.html | Test timed out.
117397 ERROR TEST-UNEXPECTED-FAIL | /tests/modules/plugin/test/test_painting.html | Test timed out.
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1279741916.1279745780.14077.gz
Rev3 Fedora 12x64 mozilla-central debug test mochitests-4/5 on 2010/07/21 12:51:56
Blocks: 578591
No longer blocks: 563663
Histogram:
   1310720: (  0,  0,  0) #000000 black

http://tinderbox.mozilla.org/showlog.cgi?tree=MozillaTry&errorparser=unittest&logfile=1281009081.1281013191.30027.gz&buildtime=1281009081&buildname=Rev3%20Fedora%2012x64%20tryserver%20debug%20test%20mochitests-4%2f5&fulltext=1#err1

Other info:

Screen Saver:
  prefer blanking:  yes    allow exposures:  yes
  timeout:  0    cycle:  0

DPMS (Energy Star):
  Standby: 0    Suspend: 0    Off: 0
  DPMS is Enabled
  Monitor is On

DPMS has not switched the monitor off.
I assume that a screen saver timeout of 0 means that it will not activate automatically.

The screen saver can be activated in other ways though. (e.g. xset q activate)
I wonder what might do that?
man XScreenSaverQueryInfo:

       This extension exports the notion of a special screen saver window that
       is mapped above all other windows on a display.  
                               ...  Furthermore, the X identifier for the win‐
       dow  is  never returned by QueryTree requests on the root window, so it
       is typically not visible to other clients.
Depends on: 585286
Whiteboard: [orange] → [orange][screensaver]
No longer blocks: 578591
No longer blocks: 569974
No longer blocks: 569425
No longer blocks: 569238
No longer blocks: 557456
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1281196936.1281198747.2841.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitests-4/5 on 2010/08/07 09:02:16

10808 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_flush_on_paint.html | Test timed out.
39712 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_mozPaintCount.html | Test timed out.
41095 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_invalidate_during_plugin_paint.html | Test timed out.
120194 ERROR TEST-UNEXPECTED-FAIL | /tests/modules/plugin/test/test_painting.html | Test timed out.
120195 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up.
120196 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 15 remaining tests.
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1281236359.1281240657.8165.gz
Rev3 Fedora 12 mozilla-central debug test mochitests-4/5 on 2010/08/07 19:59:19

:  file_get_contents() [
]: SSL: connection timeout in
on line
:  file_get_contents() [
]: Failed to enable crypto in
on line
:  file_get_contents(https://api-dev.bugzilla.mozilla.org/latest/bug?whiteboard=orange&summary=test_flush_on_paint.html) [
]: failed to open stream: operation failed in
on line
s: talos-r3-fed-027
10485 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_flush_on_paint.html | Test timed out.
37672 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_mozPaintCount.html | Test timed out.
39063 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_invalidate_during_plugin_paint.html | Test timed out.
118162 ERROR TEST-UNEXPECTED-FAIL | /tests/modules/plugin/test/test_painting.html | Test timed out.
118163 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up.
118164 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 15 remaining tests.
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1281266328.1281268115.6648.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitests-4/5 on 2010/08/08 04:18:48

s: talos-r3-fed64-018
10880 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_flush_on_paint.html | Test timed out.
39772 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/base/tests/test_mozPaintCount.html | Test timed out.
41155 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_invalidate_during_plugin_paint.html | Test timed out.
120254 ERROR TEST-UNEXPECTED-FAIL | /tests/modules/plugin/test/test_painting.html | Test timed out.
120255 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up.
120256 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 15 remaining tests.
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
PROCESS-CRASH | Main app process exited normally | application crashed (minidump found)
Thread 0 (crashed)
Bug 585286 was fixed today, which should help this (given that it is marked [scrensaver]).
Status: NEW → RESOLVED
Closed: 14 years ago
Resolution: --- → DUPLICATE
No longer depends on: 585286
Whiteboard: [orange][screensaver] → [screensaver]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: