Closed Bug 907162 Opened 7 years ago Closed 7 years ago

Intermittent test_no_load_event.html | [SimpleTest.finish()] this test already called finish! | called finish() multiple times

Categories

(Core :: Audio/Video, defect)

ARM
Gonk (Firefox OS)
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla31
Tracking Status
firefox28 --- wontfix
firefox29 --- fixed
firefox30 --- fixed
firefox31 --- fixed
firefox-esr24 --- unaffected
b2g-v1.3 --- fixed
b2g-v1.3T --- fixed
b2g-v1.4 --- fixed
b2g-v2.0 --- fixed

People

(Reporter: emorley, Assigned: jwwang)

References

Details

(Keywords: intermittent-failure)

Attachments

(3 files)

b2g_emulator_vm mozilla-inbound opt test mochitest-3 on 2013-08-20 02:22:03 PDT for push 504839bcbddc

slave: tst-linux64-ec2-111

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

{
02:32:40     INFO -  795 INFO TEST-PASS | /tests/content/media/test/test_new_audio.html | We should get to the end. Oh look we did.
02:32:40     INFO -  796 INFO TEST-PASS | /tests/content/media/test/test_new_audio.html | [finished owl.mp3-2] Length of array should match number of running tests
02:32:40     INFO -  797 INFO TEST-PASS | /tests/content/media/test/test_new_audio.html | We should get to the end. Oh look we did.
02:32:40     INFO -  798 INFO TEST-PASS | /tests/content/media/test/test_new_audio.html | [finished small-shot.m4a-3] Length of array should match number of running tests
02:32:40     INFO -  799 INFO TEST-INFO | /tests/content/media/test/test_new_audio.html | Finished at Tue Aug 20 2013 09:32:34 GMT+0000 (GMT) (1376991154.405s)
02:32:40     INFO -  800 INFO TEST-INFO | /tests/content/media/test/test_new_audio.html | Running time: 6.371s
02:32:40     INFO -  801 INFO TEST-END | /tests/content/media/test/test_new_audio.html | finished in 7398ms
02:32:40     INFO -  802 INFO TEST-START | /tests/content/media/test/test_no_load_event.html
02:32:40     INFO -  System JS : ERROR chrome://specialpowers/content/SpecialPowersObserverAPI.js:183
02:32:40     INFO -                       NS_ERROR_UNEXPECTED: Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIPrefBranch.getBoolPref]
02:32:40     INFO -  803 INFO TEST-PASS | /tests/content/media/test/test_no_load_event.html | Should not receive a load on the video element
02:32:40     INFO -  804 INFO TEST-PASS | /tests/content/media/test/test_no_load_event.html | Should not receive a load on the video element
02:32:40     INFO -  805 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_no_load_event.html | [SimpleTest.finish()] this test already called finish!
02:32:40     INFO -  806 ERROR TEST-UNEXPECTED-FAIL | /tests/content/media/test/test_no_load_event.html | called finish() multiple times
}
Closing inactive keywords:intermittent-failure bugs where the TBPLbot has previously commented and the test isn't marked as disabled; filter on orange-cleanup-201401.
Status: NEW → RESOLVED
Closed: 7 years ago
Resolution: --- → WORKSFORME
Status: RESOLVED → REOPENED
Resolution: WORKSFORME → ---
Assignee: nobody → jwwang
There are 2 bugs in the state machine scheduling:

Bug 1:
a. When it is in the middle of state machine loop (|mIsRunning| is true), |MediaDecoderStateMachine::ScheduleStateMachine| will set |mRunAgain| to true and return.
b. Then |ScheduleStateMachine| is called with |aUsecs| > 0. It fails to realize that a pending task will be run soon for |mRunAgain| is true and try to schedule a timer task to run later.
c. We will run the state machine 2 more times for there are 2 pending tasks. (One is the logical pending task triggered by |mRunAgain| is true, another is the timer task)
d. |RunStateMachine| runs twice in the state of |DECODER_STATE_COMPLETED| and sends |MediaDecoder::PlaybackEnded| twice.

Bug 2:
In |RunStateMachine|, it checks |mDecoder->GetState()| to send |MediaDecoder::PlaybackEnded|. However, the change is asynchronous and |MediaDecoder::PlaybackEnded| could be sent twice before the change in main thread is complete. Therefore, we get 'ended' event twice from HTMLMediaElement.
Attachment #8392025 - Flags: review?(paul)
Btw, the logic of |MediaDecoderStateMachine::ScheduleStateMachine| is complicated which depends on several variables (ex: mTimeout, mIsRunning, mRunAgain, and mDispatchedRunEvent). And we have 2 ways to dispatch next state machine run (one by runnable, the other by timer). I would like to refactor the code once this bug is stablized.
Blocks: 977946
Blocks: 982399
Blocks: 982234
Comment on attachment 8392025 [details] [diff] [review]
part1_fix-v1.patch

Review of attachment 8392025 [details] [diff] [review]:
-----------------------------------------------------------------

I think cpearce is a better reviewer here.
Attachment #8392025 - Flags: review?(paul) → review?(cpearce)
Attachment #8392025 - Flags: review?(cpearce) → review+
https://hg.mozilla.org/mozilla-central/rev/c298b8aa94c9
Status: REOPENED → RESOLVED
Closed: 7 years ago7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla31
Blocks: 985233
Looking good here. Please request approval for aurora, beta, and b2g28 :)
Flags: needinfo?(jwwang)
[Approval Request Comment]
Bug caused by (feature/regressing bug #): unkown
User impact if declined: none
Testing completed (on m-c, etc.): try: https://tbpl.mozilla.org/?tree=Try&rev=df02542270e6
Risk to taking this patch (and alternatives if risky): low
String or IDL/UUID changes made by this patch: none
Attachment #8395516 - Flags: review+
Attachment #8395516 - Flags: approval-mozilla-aurora?
Flags: needinfo?(jwwang)
[Approval Request Comment]
Bug caused by (feature/regressing bug #): unknown
User impact if declined: none
Testing completed (on m-c, etc.): try: https://tbpl.mozilla.org/?tree=Try&rev=c6442ec16d25
Risk to taking this patch (and alternatives if risky): low
String or IDL/UUID changes made by this patch: none
Attachment #8395533 - Flags: review+
Attachment #8395533 - Flags: approval-mozilla-beta?
JW. I am not sure to understand this uplift request. Indeed, if the "User impact if declined" is "none", why should we approve this patch?
Flags: needinfo?(jwwang)
This bug causes 'ended' event sent twice from an media element. User code depending on the 'ended' event will be impacted. But I can't come out a practical user case how this bug will affect the user code. I request for approval to stop the oranges on TBPL caused by this bug.
Flags: needinfo?(jwwang)
User impact: Intermittent failures result in tests being disabled or hidden by sheriffs & also undermine the credibility of said tests. Reduced media test coverage means a greater risk of regressions for a wider range of functionality than touched by this fix, which will mean not landing this can still effect end users.
Group: core-security
Sigh, miss press on touch screen
Group: core-security
Comment on attachment 8395516 [details] [diff] [review]
part1_fix_aurora.patch

ok, thanks for the explanation.
Attachment #8395516 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Attachment #8395533 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Comment on attachment 8395533 [details] [diff] [review]
part1_fix_beta.patch

[Approval Request Comment]
Bug caused by (feature/regressing bug #): unknown
User impact if declined: reduced media test coverage
Testing completed (on m-c, etc.): try: https://tbpl.mozilla.org/?tree=Try&rev=c6442ec16d25, already on m-c, about to land on aurora/beta as well
Risk to taking this patch (and alternatives if risky): low
String or IDL/UUID changes made by this patch: none
Attachment #8395533 - Flags: approval-mozilla-b2g28?
Attachment #8395533 - Flags: approval-mozilla-b2g28? → approval-mozilla-b2g28+
(In reply to Ed Morley [:edmorley UTC+0] from comment #63)
> User impact: Intermittent failures result in tests being disabled or hidden
> by sheriffs & also undermine the credibility of said tests. Reduced media
> test coverage means a greater risk of regressions for a wider range of
> functionality than touched by this fix, which will mean not landing this can
> still effect end users.

Good point! Thanks. :)
You need to log in before you can comment on or make changes to this bug.