921197 - Intermittent test_convolverNodeChannelCount.html,test_audioParamExponentialRamp.html | Test timed out. | [SimpleTest.finish()] this test already called finish! | called finish() multiple times

Status: RESOLVED DUPLICATE of bug 942543

(Core :: Web Audio, defect)

Description

[Ryan VanderMeulen [:RyanVM]]

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

Comment 1

[Karl Tomlinson (:karlt)]

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.

Comment 2

[(no longer active)]

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?

Comment 3

[Robert O'Callahan (:roc) (email my personal email if necessary)]

No.

Comment 4

[Ryan VanderMeulen [:RyanVM]]

https://tbpl.mozilla.org/php/getParsedLog.php?id=28471235&tree=Mozilla-Inbound

Comment 5

[Karl Tomlinson (:karlt)]

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.