Timeout after browser_privatebrowsing_cookieacceptdialog.js | must wait for focus

RESOLVED WORKSFORME

Status

()

defect
RESOLVED WORKSFORME
9 years ago
6 years ago

People

(Reporter: dbaron, Unassigned)

Tracking

({intermittent-failure})

Trunk
All
Linux
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

Attachments

(4 attachments)

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273694408.1273695478.7537.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitest-other on 2010/05/12 13:00:08  

Running chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js...
TEST-PASS | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | The remember checkbox should exist
TEST-PASS | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | The checkbox should not be disabled
TEST-PASS | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | The remember checkbox should exist
TEST-PASS | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | The checkbox should be disabled
TEST-INFO | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | Console message:
TEST-PASS | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | The remember checkbox should exist
TEST-PASS | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | The checkbox should not be disabled
TEST-INFO | checking window state
TEST-INFO | (browser-test.js) | Waiting for window activation...
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output

Updated

9 years ago
Whiteboard: [orange] → [orange][possible dupe of bug 543278]
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273760236.1273761048.15846.gz
Rev3 Fedora 12 mozilla-central opt test mochitest-other on 2010/05/13 07:17:16
s: talos-r3-fed-017
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273794877.1273796660.26922.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitest-other on 2010/05/13 16:54:37
s: talos-r3-fed64-026
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1273952075.1273953282.1611.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitest-other on 2010/05/15 12:34:35
s: talos-r3-fed64-019

Comment 5

9 years ago
This should be fixed my patch in bug 543278.

Please reopen if you see this on trunk from this point on.
Assignee: nobody → ehsan
Status: NEW → RESOLVED
Last Resolved: 9 years ago
Depends on: 543278
Resolution: --- → FIXED
Whiteboard: [orange][possible dupe of bug 543278] → [orange][fixed by bug 543278]
Flags: in-testsuite-
Whiteboard: [orange][fixed by bug 543278] → [fixed by bug 543278] [orange]
Target Milestone: --- → Firefox 3.7a5
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1274431254.1274433072.22092.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitest-other on 2010/05/21 01:40:54
s: talos-r3-fed64-026

TEST-PASS | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | must wait for focus
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
Status: RESOLVED → REOPENED
Flags: in-testsuite-
Resolution: FIXED → ---
Summary: Timeout from or after browser_privatebrowsing_cookieacceptdialog.js with TEST-INFO | (browser-test.js) | Waiting for window activation... → Timeout after browser_privatebrowsing_cookieacceptdialog.js | must wait for focus
Whiteboard: [fixed by bug 543278] [orange] → [orange]
Target Milestone: Firefox 3.7a5 → ---

Comment 7

9 years ago
I'm out of ideas here.  We probably need someone who knows about the internals of the focus code and how it works on Linux to help here.
Assignee: ehsan → nobody
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275428093.1275429395.8455.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitest-other on 2010/06/01 14:34:53
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275520154.1275522232.17115.gz
Rev3 Fedora 12 mozilla-central opt test mochitest-other on 2010/06/02 16:09:14
s: talos-r3-fed-029
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275596897.1275598013.19318.gz
Rev3 Fedora 12 mozilla-central opt test mochitest-other on 2010/06/03 13:28:17
s: talos-r3-fed-024
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275678231.1275679485.16392.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitest-other on 2010/06/04 12:03:51
s: talos-r3-fed64-030
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1275992114.1275992981.21982.gz
Rev3 Fedora 12 mozilla-central opt test mochitest-other on 2010/06/08 03:15:14
s: talos-r3-fed-004
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276122073.1276124346.16717.gz
Rev3 Fedora 12 mozilla-central opt test mochitest-other on 2010/06/09 15:21:13
s: talos-r3-fed-008
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276123738.1276126615.27689.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitest-other on 2010/06/09 15:48:58
s: talos-r3-fed64-039
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1276191687.1276192799.452.gz
Rev3 Fedora 12x64 mozilla-central opt test mochitest-other on 2010/06/10 10:41:27
s: talos-r3-fed64-012
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)
philringnalda%gmail.com
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1278641383.1278642291.32184.gz
Rev3 Fedora 12 mozilla-central opt test mochitest-other on 2010/07/08 19:09:43

s: talos-r3-fed-008
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)
TEST-UNEXPECTED-FAIL | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | application timed out after 330 seconds with no output
PROCESS-CRASH | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | application crashed (minidump found)
Thread 0 (crashed)
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 60

9 years ago
Some logging I added gives a bit more info.

Broken: http://mozilla.pastebin.com/4r6FFrTP
Working: http://mozilla.pastebin.com/ukKDWerp

Search for 'YEAH'. This is where it fails. After that, some attempts are made in various ways to focus the window. At this point, within SetFocus, no attempt is made to raise (present) the window as gtk believes that the window is already focused (gtk is correct, the window is raised and looks active)

Oddly, in the working case, after a call to raise the window, a window lowered event then comes in for that very window, followed by the window raise event. (the few lines after YEAH)

I don't see any other differences, but I'd welcome it if someone saw something I may have missed.

Of interest is that the modal event loop is entered recursively rather than entering, exiting and cleaning up after each step.
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)

Comment 63

9 years ago

Comment 64

9 years ago
The problem with this bug (and the browser_privatebrowsing_beforeunload_enter/exit.js tests) may be that there is a window activation event for the parent window on the event queue when the dialog is set as modal. This causes the event to get ignored in ContainerFocusIn as the parent window isn't enabled.

This quick fix to just process events doesn't seem to cause any problems. I had it running repeatedly on one of the build machines running the private browsing tests overnight over and over and it never failed, yet without this it fails after a few runs through (the script stops running when a timeout occurs). 

This doesn't seem like it should be the right fix, but perhaps it inspires some ideas?
Attachment #464511 - Flags: feedback?(matspal)
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)
Hardware: x86 → All
Comment on attachment 464511 [details] [diff] [review]
patch which seems to fix

This patch doesn't make any difference for me - the test hangs with or
without it.  (I'll attach a mochitest log snippet)

Regarding the suggested fix, the code doesn't do what the comment says -
NS_ProcessPendingEvents' 2nd param is a PRIntervalTime (ie. a PRUint32),
so calling it with PR_FALSE will process at most one event. I assume
this is not what you intended?  I fixed that and submitted it to
TryServer and got a hang in
browser/components/places/tests/browser/browser_sidebarpanels_click.js
with nested nsXULWindow::ShowModal on the stack:
http://tinderbox.mozilla.org/showlog.cgi?log=MozillaTry/1281917785.1281918664.25264.gz#err0

Then I tried limiting the event processing using a sentinel event
and that passed on TryServer (without
privatebrowsing_cookieacceptdialog.js though which still hangs).

But, after playing with it for a while I don't think this is the
right approach, it feels wrong to process arbitrary events before
starting the modal loop.  We could try to peek at the first event to
see if it's an activation event for the 'this' window and process
that only.  BTW, do you remember why the test failed with this
missing event?  Was it the dialog that didn't get focus/activated?
or was it the activation after the dialog goes away that failed?
or something else?

I'm assuming this activation event is due to window activation
being async on GTK platforms?

Karl may have some ideas.
Attachment #464511 - Flags: feedback?(matspal) → feedback-
This is what the log looks like when the browser_privatebrowsing_cookieacceptdialog.js test hangs

Comment 76

9 years ago
> But, after playing with it for a while I don't think this is the
> right approach, it feels wrong to process arbitrary events before
> starting the modal loop.  We could try to peek at the first event to
> see if it's an activation event for the 'this' window and process
> that only.  BTW, do you remember why the test failed with this
> missing event?  Was it the dialog that didn't get focus/activated?
> or was it the activation after the dialog goes away that failed?
> or something else?

Comment 60 provides logs with additional debugging and details of how this fails.
Sorry, I missed comment 60 in all the TinderboxPushlog spam.
Looking at the logs I still don't understand exactly why the
test fails when the activation event is ignored.

Also, is there a new bug to deal with now that the test
also hangs with the patch applied?

Comment 78

8 years ago
I believe I hit this on 3.6.14 release but it does not mention anything about focus; is it related?:

TEST-PASS | chrome://mochikit/content/browser/browser/components/privatebrowsing/test/browser/browser_privatebrowsing_cookieacceptdialog.js | The checkbox should not be disabled
Waiting for window activation...
TEST-UNEXPECTED-FAIL | automation.py | application timed out after 330 seconds with no output
INFO | automation.py | Application ran for: 0:06:54.748627
INFO | automation.py | Reading PID log: /tmp/tmp8Fo8F_pidlog
==> process 6899 launched child process 6933
INFO | automation.py | Checking for orphan process with PID: 6933
PROCESS-CRASH | automation.py | application crashed (minidump found)
WARNING | automationutils.processLeakLog() | refcount logging is off, so leaks can't be detected!
WARNING | automationutils.processLeakLog() | refcount logging is off, so leaks can't be detected!

INFO | runtests.py | Running tests: end.

INFO | runtests.py | Running tests: end.

Comment 79

8 years ago
It hangs while waiting for the window to be activated, so yes.
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Whiteboard: [orange]
Resolving WFM keyword:intermittent-failure bugs last modified >3 months ago, whose whiteboard contains none of:
{random,disabled,marked,fuzzy,todo,fails,failing,annotated,time-bomb,leave open}

There will inevitably be some false positives; for that (and the bugspam) I apologise. Filter on orangewfm.
Status: REOPENED → RESOLVED
Last Resolved: 9 years ago6 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.