https://tbpl.mozilla.org/php/getParsedLog.php?id=28417445&tree=Mozilla-Inbound Rev4 MacOSX Snow Leopard 10.6 mozilla-inbound opt test mochitest-1 on 2013-09-26 10:43:39 PDT for push 5d5f51249cb8 slave: talos-r4-snow-032 11:07:59 INFO - 161761 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Expect a DOM exception 11:07:59 INFO - 161762 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Expect the correct exception code 11:07:59 INFO - 161763 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | The exception was thrown 11:07:59 INFO - 161764 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Expect a DOM exception 11:07:59 INFO - 161765 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Expect the correct exception code 11:07:59 INFO - 161766 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | The exception was thrown 11:07:59 INFO - 161767 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Correct number of input buffer channels 11:07:59 INFO - 161768 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Found 0 different samples, maxDifference: 0, first bad index: -1 with source offset 0 and destination offset 0 11:07:59 INFO - 161769 INFO TEST-PASS | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Found 0 different samples, maxDifference: 0, first bad index: -1 with source offset 0 and destination offset 0 11:07:59 INFO - 161770 INFO TEST-END | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | finished in 104ms 11:13:28 INFO - SCREENSHOT: <see log> 11:13:28 INFO - 161771 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Test timed out. 11:13:28 INFO - 161772 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | [SimpleTest.finish()] this test already called finish! 11:13:28 INFO - 161773 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | called finish() multiple times 11:13:55 INFO - Not taking screenshot here: see the one that was previously logged 11:13:55 INFO - 161774 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Test timed out. 11:13:56 INFO - 161775 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | [SimpleTest.finish()] this test already called finish! 11:13:56 INFO - 161776 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | called finish() multiple times 11:14:25 INFO - Not taking screenshot here: see the one that was previously logged 11:14:25 INFO - 161777 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Test timed out. 11:14:26 INFO - 161778 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | [SimpleTest.finish()] this test already called finish! 11:14:26 INFO - 161779 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | called finish() multiple times 11:14:55 INFO - Not taking screenshot here: see the one that was previously logged 11:14:55 INFO - 161780 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | Test timed out. 11:14:55 INFO - 161781 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up. 11:14:55 INFO - 161782 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 176 remaining tests. 11:14:56 INFO - 161783 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | [SimpleTest.finish()] this test already called finish! 11:14:56 INFO - 161784 ERROR TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | called finish() multiple times 11:20:26 WARNING - TEST-UNEXPECTED-FAIL | /tests/content/media/webaudio/test/test_convolverNodeChannelCount.html | application timed out after 330 seconds with no output 11:20:26 INFO - Not taking screenshot here: see the one that was previously logged 11:20:26 INFO - Can't trigger Breakpad, just killing process 11:20:26 INFO - Failed to kill process 880: [Errno 3] No such process 11:20:26 INFO - INFO | runtests.py | exit 9 11:20:26 INFO - INFO | runtests.py | Application ran for: 0:33:21.176263 11:20:26 INFO - INFO | zombiecheck | Reading PID log: /var/folders/xo/xof2YhG8G8G4l8Q8AaPJZ++++-k/-Tmp-/tmpzmPZWKpidlog 11:20:26 INFO - WARNING | leakcheck | refcount logging is off, so leaks can't be detected! 11:20:26 INFO - runtests.py | Running tests: end. 11:20:26 ERROR - Return code: 2304

Looks like OfflineDestinationNodeEngine::ProduceAudioBlock() may call SendBufferToMainThread() more than once. I've seen ProduceAudioBlock() in AudioBufferSourceNode called multiple times after returning aFinished. That's not specific to this test. Most webaudio mochitests use OfflineAudioContext::oncomplete. Not sure that is the cause of the timeout, but something that would need to be fixed anyway.

Ah, I remember something about MSG calling us even after we set *aFinished to true... But I thought I fixed that. roc, do you remember what I'm talking about?

No.

Comment 1 is not the cause of this timeout or multiple finish. OfflineDestinationNodeEngine::ProduceAudioBlock() is called more than once but SendBufferToMainThread() clears mInputChannels and so subsequent ProduceAudioBlock() calls return early.