Closed Bug 565437 Opened 14 years ago Closed 11 years ago

Timeout after browser_privatebrowsing_cookieacceptdialog.js | must wait for focus

Categories

(Firefox :: Private Browsing, defect)

Product:
Firefox
Component:
Private Browsing
Platform:
All
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED WORKSFORME

People

(Reporter: dbaron, Unassigned)

References

Details

(Keywords: intermittent-failure)

Attachments

(4 files)

debugging patch
21.58 KB, patch
Details | Diff | Splinter Review
patch which seems to fix
848 bytes, patch
MatsPalmgren_bugz
: feedback-
Details | Diff | Splinter Review
mochitest log snippet
5.35 KB, text/plain
Details
WIP: process events until sentinel event
1.89 KB, patch
Details | Diff | Splinter Review 
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
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
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
Closed: 14 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 → ---
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
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)
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.
Attached patch debugging patch — — Splinter Review 

    
    

    
  


  
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)

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  
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-

    
    

    
  

      
      
      
      

        Attached file
          
        mochitest log snippet
        — 
      

    


  
This is what the log looks like when the browser_privatebrowsing_cookieacceptdialog.js test 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?

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?

    
    

    
  
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.

    
    

    
  
It hangs while waiting for the window to be activated, so yes.

    
    

    
      
  

    
    

    
      
  

    
    

    
      
  
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
Closed: 14 years ago → 11 years ago
Resolution: --- → WORKSFORME

          You need to log in
          before you can comment on or make changes to this bug.
        






  

    
  







  

    

      
Attachment

      

      
      
      
      
    

    

      

        

          

            
General

            

              Creator: 



            

            
Created: 

            
Updated: 

            
Size: