Closed Bug 942543 Opened 11 years ago Closed 2 years ago

Mochitest failures claiming that a test which has finished timed out four times, followed by "4 test timeouts, giving up"

Categories

(Testing :: Mochitest, defect)

Product:
Testing
Component:
Mochitest
Type:
defect

Tracking

(firefox27 affected, firefox28 affected, firefox29 affected)

Status:
RESOLVED INACTIVE
Tracking Flags:
Tracking Status
firefox27 --- affected
firefox28 --- affected
firefox29 --- affected

People

(Reporter: philor, Unassigned)

References

Details

(Keywords: intermittent-failure, regression)

Destroying a run because a test which had already finished "timed out" after it finished, four times over, is naughty. I know of bug 942522, bug 942527, bug 934052 and https://tbpl.mozilla.org/php/getParsedLog.php?id=31016598&tree=Mozilla-Inbound, but there are undoubtedly others where we didn't put the "4 test timeouts, giving up" in the summary, and undoubtedly more that we didn't file. 22:28:33 INFO - 12647 INFO TEST-END | /tests/content/base/test/test_bug368972.html | finished in 154ms (screenshot) 22:33:44 INFO - 12648 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | Test timed out. 22:33:44 INFO - 12649 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | [SimpleTest.finish()] this test already called finish! 22:33:44 INFO - 12650 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | called finish() multiple times 22:34:13 INFO - Not taking screenshot here: see the one that was previously logged 22:34:13 INFO - 12651 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | Test timed out. 22:34:14 INFO - 12652 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | [SimpleTest.finish()] this test already called finish! 22:34:14 INFO - 12653 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | called finish() multiple times 22:34:43 INFO - Not taking screenshot here: see the one that was previously logged 22:34:43 INFO - 12654 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | Test timed out. 22:34:44 INFO - 12655 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | [SimpleTest.finish()] this test already called finish! 22:34:44 INFO - 12656 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | called finish() multiple times 22:35:13 INFO - Not taking screenshot here: see the one that was previously logged 22:35:13 INFO - 12657 ERROR TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | Test timed out. 22:35:13 INFO - 12658 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up. 22:35:13 INFO - 12659 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 1163 remaining tests. 22:35:14 INFO - 12660 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | [SimpleTest.finish()] this test already called finish! 22:35:14 INFO - 12661 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | called finish() multiple times 22:40:44 WARNING - TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | application timed out after 330 seconds with no output 22:40:44 INFO - Not taking screenshot here: see the one that was previously logged 22:40:46 WARNING - TEST-UNEXPECTED-FAIL | /tests/content/base/test/test_bug368972.html | application terminated with exit code 3221225477
So, started in late September?
Blocks: 746243
Keywords: regression
Flags: needinfo?(jhammel)
Flags: needinfo?(jhammel)
So, just eyeballing the logs, it's hard to see how this would be caused by bug 746243, since all the errors are local to the JS harness. But, I've learned never to say 'never'.
Sorry, didn't mean to cancel this flag
Flags: needinfo?(jhammel)
(In reply to Jonathan Griffin (:jgriffin) from comment #18) > So, just eyeballing the logs, it's hard to see how this would be caused by > bug 746243, since all the errors are local to the JS harness. But, I've > learned never to say 'never'. I'm guessing that since these occur following screenshot output that it is a strong possibility that this is a harness problem, likely a regression from bug 746243. since all of these are mac, likely a mac peculiarity? :/
Flags: needinfo?(jhammel)
status-firefox27: --- → affected
Poor little Android tried so hard, but https://tbpl.mozilla.org/php/getParsedLog.php?id=31660807&tree=Mozilla-Inbound only managed three timeouts in a test which had already finished before it blew up, rather than four.
I'll take a stab at this one.
Assignee: nobody → dminor
Must be possible for a test to contribute to this, or we're conflating some separate bustage with this, since the bulk of the recent ones are b2g emulator mochitest-7 hitting this in dom/inputmethod/mochitest/test_sendkey_cancel.html. https://tbpl.mozilla.org/php/getParsedLog.php?id=35842548&tree=B2g-Inbound
Though https://tbpl.mozilla.org/php/getParsedLog.php?id=35843090&tree=B2g-Inbound is the same suite, but dom/inputmethod/mochitest/test_delete_focused_element.html, so dunno.
Blocks: 983015
I haven't looked at this in close to 18 months and it's unlikely I'll find time in the foreseeable future.
Assignee: dminor → nobody
This is still happening over in bug 1421775, so far entirely on OSX 10.10 debug.
Severity: major → S2
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INACTIVE
You need to log in before you can comment on or make changes to this bug.