Closed Bug 873661 Opened 11 years ago Closed 10 years ago

Intermittent dom/browser-element/mochitest/priority/test_NestedFrames.html | Test timed out.

Categories

(Core :: IPC, defect)

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

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla30
Tracking Flags:
Tracking Status
firefox28 --- fixed
firefox29 --- fixed
firefox30 --- fixed
firefox-esr24 --- fixed
b2g-v1.2 --- fixed
b2g-v1.3 --- fixed
b2g-v1.3T --- fixed
b2g-v1.4 --- fixed

People

(Reporter: RyanVM, Assigned: kanru)

References

Details

(Keywords: intermittent-failure, Whiteboard: [rr][qa-])

Attachments

(1 file)

Wait both browserloadend and process-created event
1.32 KB, patch
fabrice
: review+
Details | Diff | Splinter Review 
https://tbpl.mozilla.org/php/getParsedLog.php?id=23089505&tree=Mozilla-Inbound

Ubuntu VM 12.04 mozilla-inbound opt test mochitest-2 on 2013-05-17 13:21:38 PDT for push 8ed13280c811
slave: tst-linux32-ec2-090

13:25:20     INFO -  1290 INFO TEST-START | /tests/dom/browser-element/mochitest/priority/test_NestedFrames.html
13:25:20     INFO -  NOTE: child process received `Goodbye', closing down
13:25:20     INFO -  ############################### browserElementPanning.js loaded
13:25:20     INFO -  ######################## BrowserElementChildPreload.js loaded
13:25:20     INFO -  1291 INFO TEST-PASS | /tests/dom/browser-element/mochitest/priority/test_NestedFrames.html | Got new process, id=11
13:25:20     INFO -  1292 INFO TEST-PASS | /tests/dom/browser-element/mochitest/priority/test_NestedFrames.html | Expected priority of childID 11 to change to FOREGROUND
13:25:20     INFO -  Xlib:  extension "RANDR" missing on display ":0".
13:25:20     INFO -  creating 1!
13:25:20     INFO -  [TabChild] SHOW (w,h)= (0, 0)
13:25:20     INFO -  ############################### browserElementPanning.js loaded
13:25:21     INFO -  ######################## BrowserElementChildPreload.js loaded
13:25:21     INFO -  loading http://example.com/tests/dom/browser-element/mochitest/file_empty.html, 1
13:30:30     INFO -  1293 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/browser-element/mochitest/priority/test_NestedFrames.html | Test timed out.
13:30:30     INFO -  args: ['/builds/slave/test/build/tests/bin/screentopng']
13:30:30     INFO -  Xlib:  extension "RANDR" missing on display ":0".
13:30:44     INFO -  SCREENSHOT: <see log>
13:30:44     INFO -  1294 INFO TEST-END | /tests/dom/browser-element/mochitest/priority/test_NestedFrames.html | finished in 311397ms
blocking-b2g: tef+ → ---
Hey fabrice, I have this failure saved in a trace that can be replayed deterministically over and over.  Do you know of anyone who's familiar with browser-element/DOM-y stuff and who has cycles to help debug this?  I can answer pretty much any question about the execution, and definitely any gdb queries.

What I do know is
 - as you can see in the failing log, the process is created and the priority changes to FOREGROUND
 - a PBrowser is created
 - it's sent LoadURL
 - the browser sets up layout state (PRenderFrame)
 - the browser makes an HTTP request, and it completes (child sent PHttp:OnStopRequest)
 - (the child is sent PStorage:LoadDone, but I don't know what that is)

But no mozbrowserloadevent fires, and the test times out waiting for that promise.
Flags: needinfo?(fabrice)
Hey cjones!
PStorage is the ipdl for localStorage iirc. Honza would know for sure. Do you have a trace of a not failing run of the test?

Kan-Ru owns the browser-element API now, so ni? on him anyway!
Flags: needinfo?(kchen)
Flags: needinfo?(honzab.moz)
Flags: needinfo?(fabrice)
DOM storage is not involved here at all.  PStorage:LoadDone means that DOMStorage (localStorage) data belonging the origin of the document has been loaded from the database asynchronously and localStorage access will no longer block.  I don't see the test would be working with localStorage at all, so it cannot have any influence.
Flags: needinfo?(honzab.moz)
Hi cjones!

Could I reply the trace locally? Does the docShell fire nsIWebProgressListener::STATE_STOP after nsIWebProgressListener::STATE_START? The entry point is nsDocLoader::DoFireOnStateChange.
Flags: needinfo?(kchen)
(In reply to Kan-Ru Chen [:kanru] from comment #24)
> Hi cjones!
> 
> Could I reply the trace locally?

Unfortunately no, not yet.

> Does the docShell fire
> nsIWebProgressListener::STATE_STOP after
> nsIWebProgressListener::STATE_START? The entry point is
> nsDocLoader::DoFireOnStateChange.

Let me see ...
> Does the docShell fire nsIWebProgressListener::STATE_STOP after nsIWebProgressListener::STATE_START?

With these gdb commands

(gdb) b 'nsDocLoader::DoFireOnStateChange'
(gdb) commands 1
>p (aStateFlags & 0x1f)
>c
>end

I see the following state changes

$1 = 1   [START]
$2 = 1   [START]
$3 = 1   [START]
$4 = 1   [START]
$5 = 16  [STOP | REDIRECTING | TRANSFERRING ?]
$6 = 16  [STOP | REDIRECTING | TRANSFERRING ?]
$7 = 1   [START]
$8 = 1   [START]
$9 = 4   [TRANSERRING?]
$10 = 4  [TRANSERRING?]
$11 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$12 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$13 = 1  [START]
$14 = 1  [START]
$15 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$16 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$17 = 4  [TRANSERRING?]
$18 = 4  [TRANSERRING?]
$19 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$20 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$21 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$22 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$23 = 16 [STOP | REDIRECTING | TRANSFERRING ?]
$24 = 16 [STOP | REDIRECTING | TRANSFERRING ?]

I'm not sure if that answers your question.  I can run other gdb commands if you'd like.
Flags: needinfo?(kchen)
The creation of content process is asynchronous so "browserloadend" event could fire before or after process creation. We need to wait both of them before we advance to next test.

https://tbpl.mozilla.org/?tree=Try&rev=50c5278585fe
Assignee: nobody → kchen
Status: NEW → ASSIGNED
Attachment #8377421 - Flags: review?(fabrice)
Flags: needinfo?(kchen)
Comment on attachment 8377421 [details] [diff] [review]
Wait both browserloadend and process-created event

Review of attachment 8377421 [details] [diff] [review]:
-----------------------------------------------------------------

nice!
Attachment #8377421 - Flags: review?(fabrice) → review+
Nice find. ++kanru
https://hg.mozilla.org/mozilla-central/rev/de767cef4a63
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla30
status-b2g-v1.3: --- → fixed
Whiteboard: [rr] → [rr][qa-]
Fwiw, this went from reproducing in about 1/2 runs to no longer being reproducible.
status-b2g-v1.3T: --- → fixed
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: