Open
Bug 510001
Opened 15 years ago
Updated 2 years ago
mochitest-plain: intermittent "test_bug507902.html | Test timed out"
Categories
(Core :: Layout, defect, P5)
Tracking
()
REOPENED
mozilla1.9.2b1
People
(Reporter: jrmuizel, Unassigned)
References
(Blocks 1 open bug)
Details
(Keywords: intermittent-failure, Whiteboard: [test is disabled])
Attachments
(3 files)
(deleted),
patch
|
Waldo
:
review+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
Details | Diff | Splinter Review | |
(deleted),
patch
|
Details | Diff | Splinter Review |
Updated•15 years ago
|
Assignee: nobody → bobbyholley
Comment 1•15 years ago
|
||
pushed fix to mc in bug 9bcf62d5073b. Optimistically resolving as fixed. Please re-open if you see this again.
Status: NEW → RESOLVED
Closed: 15 years ago
Resolution: --- → FIXED
Updated•15 years ago
|
Target Milestone: --- → mozilla1.9.2b1
Comment 2•15 years ago
|
||
Bug 511211 says this also happens on 1.9.1. (Not sure why it's a different bug report, though.)
Comment 3•15 years ago
|
||
Bug 511211 seems to be invalid - resolving it as such.
Comment 4•15 years ago
|
||
looks like the failure did actually reoccur, but on mc.
http://tinderbox.mozilla.org/showlog.cgi?tree=Firefox&errorparser=unittest&logfile=1250617322.1250622373.21834.gz&buildtime=1250617322&buildname=WINNT%205.2%20mozilla-central%20unit%20test&fulltext=
reopening.
I'm pretty stumped. Jeff - any ideas?
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Updated•15 years ago
|
Summary: ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_bug507902.html | Test timed out. → mochitest-plain: intermittent "test_bug507902.html | Test timed out"
Comment 6•15 years ago
|
||
I don't have any obvious ideas; the logs don't give near enough information to tell where things go astray. I'd add dumps to all the methods in there to determine which was called last; from there it should be possible to figure out more accurately what's happened.
Comment 7•15 years ago
|
||
Added a debugging dump patch to throw up onto the tinderbox. Flagging jeff for review.
Attachment #395613 -
Flags: review?
Updated•15 years ago
|
Attachment #395613 -
Flags: review? → review?(jwalden+bmo)
Comment 8•15 years ago
|
||
Comment on attachment 395613 [details] [diff] [review]
debugging patch v1
I wouldn't have bothered getting review on this, adding dump statements is a trivial enough change. :-)
Attachment #395613 -
Flags: review?(jwalden+bmo) → review+
Comment 9•15 years ago
|
||
I thought everything except bustage fixes needed review?
pushed dump patch as f00c51fa1eb4.
Comment 10•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1250872964.1250882083.18818.gz
WINNT 5.2 mozilla-central unit test on 2009/08/21 09:42:44
46044 INFO TEST-PASS | /tests/layout/generic/test/test_bug470212.html | rangeCount should be 0
46046 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
command timed out: 300 seconds without output
Comment 11•15 years ago
|
||
If it's "small enough" and merely a followup, I believe we've always been fine about not needing a review. Better to beg forgiveness than ask permission, in my book...
That debug output, assuming it works as expected when the test passes, suggests the orange is not a result of httpd.js bugs or misuses. Agree?
Comment 12•15 years ago
|
||
So what seems to be happening here is the following:
1) foo.src = url
2) function call
3) (within the function call) foo.onload = bar
4) bar never gets called, test times out
I don't know much about how events in the DOM work - is it ok to set an onload handler after setting the src? (I've seen this in several other mochitests). Does the fact that onload is set in a function call change things?
Comment 13•15 years ago
|
||
Seems like a race condition? Maybe the test should be setting the onload handler before setting .src.
Comment 14•15 years ago
|
||
Perhaps. I tend to write things in that order.
But I don't think it should matter. nsImageLoadingContent::FireEvent fires image onload events asynchronously.
Comment 15•15 years ago
|
||
dbaron - can you clarify what you mean by 'asynchronously'? If the onload handler is set after the load, does it still get called? Does control ever leave js between the time the src is set and the time the handler is set? I've read online that
img.src = foo
img.onload = bar
is known to be safe in firefox but not in ie. Is this still true?
I'd like to avoid switching the order "because it seems right." Doing so might make the problem disappear, but perhaps not actually address the root cause. I'd rather get to the bottom of it, whatever it is. Either what's happening now is safe, or it's not right?
Comment 16•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1251082926.1251085175.28276.gz
WINNT 5.2 mozilla-central test mochitests on 2009/08/23 20:02:06
Comment 17•15 years ago
|
||
just added a patch that sets a placeholder onload handler before src that will spew a warning if it ever gets called. This should help us get to the bottom of this.
Pushed to mc as 6a7bc6f644c5. r=lumpy
Comment 18•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1251236437.1251238907.20069.gz
WINNT 5.2 mozilla-central test mochitests on 2009/08/25 14:40:37
46126 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
46127 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_bug507902.html | Test timed out.
Does that help?
Comment 19•15 years ago
|
||
ted - thanks, that does help a lot. Given that I landed dummy onload handlers that were set before src, we can now rule out the "src before onload race condition" theory.
Any other ideas? Should we try setting something for onerror and see what happens?
Comment 20•15 years ago
|
||
Feel free to land whatever debugging code you deem necessary in tests without review. If it helps you fix a test (or some underlying bug), it's well worth it.
Comment 21•15 years ago
|
||
at first I thought the error might have something to do with the fact that the server port was hardcoded in the test as 8888. Ted says this shouldn't be a problem, but I left the fix in anyway. The real reason I'm pushing this patch is to see if we get onerror for the image (since according to smaug img onerror doesn't bubble).
pushed to mc as 72d25f49cbcb. r=lumpy ;-)
Comment 22•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1251823830.1251829787.16545.gz
46354 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
command timed out: 300 seconds without output
program finished with exit code 1
elapsedTime=1634.453000
TinderboxPrint: mochitest-plain<br/><em class="testfail">T-FAIL</em>
Comment 23•15 years ago
|
||
so we're not hitting onload, and we're not hitting onerror. I'm baffled - anyone else have bright ideas?
Comment 24•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1251968128.1251970577.14443.gz
WINNT 5.2 mozilla-central test mochitests on 2009/09/03 01:55:28
Comment 25•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1252107968.1252110203.27010.gz
WINNT 5.2 mozilla-central test mochitests on 2009/09/04 16:46:08
{
46185 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
46186 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_bug507902.html | Test timed out.
}
Comment 26•15 years ago
|
||
WINNT 5.2 mozilla-central test mochitests
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1252292993.1252295232.27007.gz
46181 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
46182 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_bug507902.html | Test timed out.
46184 INFO Running /tests/layout/generic/test/test_movement_by_characters.html...
Comment 27•15 years ago
|
||
WINNT 5.2 mozilla-central test mochitests
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1252301699.1252304009.23588.gz
46191 INFO TEST-PASS | /tests/layout/generic/test/test_bug503813.html | Expected hover style
46193 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
46194 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_bug507902.html | Test timed out.
46196 INFO Running /tests/layout/generic/test/test_movement_by_characters.html...
Comment 28•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1252664384.1252666798.5331.gz
WINNT 5.2 mozilla-1.9.2 test mochitests on 2009/09/11 03:19:44
Comment 29•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1252967465.1252970218.4415.gz
Linux mozilla-1.9.2 test mochitests on 2009/09/14 15:31:05
Reporter | ||
Comment 30•15 years ago
|
||
Comment 31•15 years ago
|
||
Comment 32•15 years ago
|
||
Linux mozilla-central test mochitests on 2009/09/18 05:05:31
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1253275531.1253278368.32285.gz
Comment 33•15 years ago
|
||
WINNT 5.2 mozilla-1.9.2 test mochitests on 2009/09/18 10:07:20
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox3.6-Unittest/1253293640.1253295926.11758.gz
Comment 34•15 years ago
|
||
Wait, WTF? The latest log paul posted doesn't even display the message about the test failing intermittently. So the issue is probably something that happens even earlier (maybe during SimpleTest.waitForExplicitFinish()?).
Waldo - thoughts?
Comment 35•15 years ago
|
||
That's on 1.9.2. Did you land your debug output there, or just trunk?
Comment 36•15 years ago
|
||
(In reply to comment #35)
> That's on 1.9.2. Did you land your debug output there, or just trunk?
Ahhh, that would explain it. Disregard my last comment.
Comment 37•15 years ago
|
||
Nothing more useful here:
46367 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
command timed out: 300 seconds without output
program finished with exit code 1
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1253617095.1253624854.15437.gz
Comment 38•15 years ago
|
||
Basically the same thing here, except the harness timed the test out instead of the whole thing failing:
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1253617815.1253619813.15862.gz
Comment 39•15 years ago
|
||
Ted - I know what needs to happen to make progress here (bug 515495), but it could be a while. Should we just disable the test?
Comment 40•15 years ago
|
||
That's probably the best solution, unfortunately. You're also welcome to stick some logging printfs anywhere you please in the codebase if it would help dig further. I suspect that sticking them in imagelib would result in a massive amount of spew, so maybe not practical.
Comment 41•15 years ago
|
||
Ted - I need to head out in a sec and I don't have a clean tree. Can you push a disable patch when you get the chance?
Comment 42•15 years ago
|
||
I just hit this...
46204 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
http://tinderbox.mozilla.org/showlog.cgi?log=TraceMonkey/1253753164.1253758692.14001.gz
Comment 43•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1253829452.1253831342.17238.gz
WINNT 5.2 mozilla-central test opt mochitests on 2009/09/24 14:57:32
Same as comment 42.
Comment 44•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1254398959.1254400950.31489.gz
Linux mozilla-central test opt mochitests on 2009/10/01 05:09:19
47249 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
test_bug507902.html DEBUG - Current Stage: 1
test_bug507902.html DEBUG - Current Stage: 2
test_bug507902.html DEBUG - Current Stage: 3
test_bug507902.html DEBUG - Current Stage: 4
test_bug507902.html DEBUG - Current Stage: 5
test_bug507902.html DEBUG - Current Stage: 6
test_bug507902.html DEBUG - Current Stage: 7
test_bug507902.html DEBUG - starting server load
file_IconTestServer.js DEBUG - Got initial request
file_IconTestServer.js DEBUG - Playing the waiting game
test_bug507902.html DEBUG - Current Stage: 8
test_bug507902.html DEBUG - drawing loading icon
test_bug507902.html DEBUG - Current Stage: 9
test_bug507902.html DEBUG - signaling server to continue
file_IconTestServer.js DEBUG - Got continue command
test_bug507902.html DEBUG - Current Stage: 10
47250 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_bug507902.html | Test timed out.
Comment 45•15 years ago
|
||
Linux mozilla-central test opt mochitests
Started 08:49, finished 09:22
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1254412162.1254414117.24299.gz&fulltext=1
Comment 46•15 years ago
|
||
WINNT 5.2 mozilla-central test mochitests Started 11:06, finished 11:49
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1254420376.1254422916.29391.gz&fulltext=1
Comment 47•15 years ago
|
||
59504 INFO Running /tests/layout/generic/test/test_bug507902.html...
This test is failing intermittently, see bug 510001 - If you see orange here, please paste the following debugging output on the bug!
test_bug507902.html DEBUG - Current Stage: 0
59505 ERROR TEST-UNEXPECTED-FAIL | /tests/layout/generic/test/test_bug507902.html | Test timed out.
bholley, any update on looking into this? It seems to be happening fairly frequently.
Comment 48•15 years ago
|
||
Comment 49•15 years ago
|
||
It'll be a bit before we have the logging capabilities to tackle this (bug 515495).
Pushed a disable to mc as 08ac2d3caca8.
Comment 50•15 years ago
|
||
landed on 192 as 21d9599fc6bf.
Updated•15 years ago
|
Whiteboard: [orange] → [orange][test is disabled]
Comment 51•13 years ago
|
||
I'll have my hands full with XPConnect and js-ctypes for the foreseeable future - resetting assignee to default.
Assignee: bobbyholley+bmo → nobody
Assignee | ||
Updated•12 years ago
|
Keywords: intermittent-failure
Assignee | ||
Updated•12 years ago
|
Whiteboard: [orange][test is disabled] → [test is disabled]
Updated•11 years ago
|
Priority: -- → P5
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Comment hidden (Legacy TBPL/Treeherder Robot) |
Updated•2 years ago
|
Severity: normal → S3
You need to log in
before you can comment on or make changes to this bug.
Description
•