Open
Bug 1068951
Opened 10 years ago
Updated 2 years ago
Mochitests may be reported as timing out, when they actually completed >20 seconds shy of the limit. (possibly "timing out" due to a post-test-completion GC)
Categories
(Testing :: Mochitest, defect)
Tracking
(Not tracked)
NEW
People
(Reporter: dholbert, Unassigned)
Details
Attachments
(1 file)
(deleted),
text/plain
|
Details |
As noted in bug 1041075 comment 136, we've got a log there with these facts:
Test: test_value_storage.html
Allowed time: 15 min (900000ms)
Test runtime: 14 min 38s (878560ms)
...and yet the test is reported as timing out.
This ends up looking like this in the TBPL log:
{
> INFO - 83 INFO TEST-START | /tests/layout/style/test/test_value_storage.html
> INFO - 84 INFO TEST-OK | /tests/layout/style/test/test_value_storage.html | took 878560ms
> INFO - 85 INFO TEST-UNEXPECTED-FAIL | /tests/layout/style/test/test_value_storage.html | Test timed out. - expected PASS
> INFO -
> INFO - 86 INFO TEST-UNEXPECTED-FAIL | /tests/layout/style/test/test_value_storage.html | Test timed out. - Result logged after SimpleTest.finish()
}
The android logcat output has more information (including all the individual sub-test results). In particular, it shows there being some GC'ing between the "test finished" message and the reported timeout. I'm assuming that's the cause of the discrepancy.
We should fix things here to make the messaging consistent. (Either the test finished in its allotted time, or it did not; but right now, our logging is saying that it *both* did *and* did not.)
In particular, we should either:
(1) Make the post-test GC officially part of the test (and not print a "test finished in..." message until it's complete)
...OR:
(2) Make the post-test GC officially *NOT* part of the test, and don't count it against the test's allotted time.
Reporter | ||
Updated•10 years ago
|
Summary: Mochitests may be reported as timing out, when they actually completed >20 seconds shy of the limit. (possibly due to a post-test-completion GC) → Mochitests may be reported as timing out, when they actually completed >20 seconds shy of the limit. (possibly "timing out" due to a post-test-completion GC)
Reporter | ||
Comment 1•10 years ago
|
||
Here are the links to the logs from the testrun that prompted me to file this bug:
TBPL Log: https://tbpl.mozilla.org/php/getParsedLog.php?id=47819311&tree=Mozilla-Inbound
Full logcat: http://mozilla-releng-blobs.s3.amazonaws.com/blobs/mozilla-inbound/sha512/39291468a5542b31a3461bc0b7b6ed24dfc129c8f0ade16d6d461dc746521c2d2810f3e8795f22220c555c6db96b78f6104f9761c9107c1b45624344a4ad632a
I'm attaching a pruned version of the logcat output, showing this test starting, finishing, and then being reported as a timeout after a GC happens.
Updated•2 years ago
|
Severity: normal → S3
You need to log in
before you can comment on or make changes to this bug.
Description
•