Closed Bug 1023552 Opened 5 years ago Closed 4 years ago

Intermittent test_audio_wakelock.html | There was at least 200 milliseconds between the stop and the wakelock release

Categories

(Core :: Hardware Abstraction Layer (HAL), defect)

ARM
Android
defect
Not set

Tracking

()

RESOLVED WORKSFORME
mozilla35
Tracking Status
firefox33 --- wontfix
firefox34 --- fixed
firefox35 --- fixed
firefox-esr31 --- unaffected
b2g-v2.0 --- unaffected
b2g-v2.0M --- unaffected
b2g-v2.1 --- fixed
b2g-v2.2 --- fixed

People

(Reporter: RyanVM, Assigned: jwwang)

Details

(Keywords: intermittent-failure)

Attachments

(1 file, 1 obsolete file)

+++ This bug was initially created as a clone of Bug #881443 +++

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

Android 2.2 Armv6 Tegra b2g-inbound opt test mochitest-2 on 2014-06-10 13:27:12 PDT for push 98deb29a6c1f
slave: tegra-286

24922 INFO TEST-START | /tests/content/html/content/test/test_audio_wakelock.html
24923 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | Audio element locked the target == cpu
24924 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | Audio element locked the cpu - no paused
24925 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | Audio element locked the target == cpu
24926 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | Audio element locked the cpu - no paused
24927 INFO TEST-UNEXPECTED-FAIL | /tests/content/html/content/test/test_audio_wakelock.html | There was at least 200 milliseconds between the stop and the wakelock release
24928 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | Audio element locked the target == cpu
24929 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | Audio element locked the cpu - no paused
24930 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | Audio element locked the target == cpu
24931 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | Audio element locked the cpu - no paused
24932 INFO TEST-PASS | /tests/content/html/content/test/test_audio_wakelock.html | There was at least 200 milliseconds between the stop and the wakelock release
24933 INFO TEST-INFO | MEMORY STAT vsize after test: 596246528
24934 INFO TEST-INFO | MEMORY STAT residentFast after test: 163438592
24935 INFO TEST-INFO | MEMORY STAT heapAllocated after test: 30078676
24936 INFO TEST-END | /tests/content/html/content/test/test_audio_wakelock.html | finished in 7301ms
It is not right to check the interval between 'progess' event [1] and wakelock release event since 'progress' event is related to download instead of wakelock. A media element can download data while paused and 'progess' events will fire regularly.

What is the 200ms delay for? Is it to prevent quick flipping between wakelock acquire and release?

[1] http://hg.mozilla.org/mozilla-central/file/4534f97c4633/content/html/content/test/test_audio_wakelock.html#l79
Flags: needinfo?(amarchesini)
That test should check that, when the audio starts playing we have the resource locked. Then when it stops playing (no pause() is used here), the resource is unlock after 200 milliseconds.

In bug 872430 we implemented a timeout for the Wakelock releasing.

The reason why I use 'progress' is because I think when the audio file is finished no progress events are dispatched.
Flags: needinfo?(amarchesini)
(In reply to Andrea Marchesini (:baku) from comment #5)
> That test should check that, when the audio starts playing we have the
> resource locked. Then when it stops playing (no pause() is used here), the
> resource is unlock after 200 milliseconds.

That wouldn't make much sense for a file whose duration is larger than 200ms. Instead, I think we can try to call pause() immediately after play() and we should expect wakelock release event should be at least 200ms later than the wakelock acquire event. Thought?
(In reply to Andrea Marchesini (:baku) from comment #5)
> The reason why I use 'progress' is because I think when the audio file is
> finished no progress events are dispatched.

It is possible for the media element to download the whole file even before metadata is decoded. Then there won't be any 'progress' event during the whole process of playback. It is also possible for download end and playback end to arrive almost at the same time. For 'ended' and 'progress' events are dispatched asynchronously, chances are we get a 'progress' event after 'ended' event is received.
> That wouldn't make much sense for a file whose duration is larger than
> 200ms. Instead, I think we can try to call pause() immediately after play()
> and we should expect wakelock release event should be at least 200ms later
> than the wakelock acquire event. Thought?

This is what test 1 (testAudioPlayPause) does. The test 2 (testAudioPlay) tests it without pause.
If this cannot be tested properly, I'm fine to remove this second test.
I see. I will remove the second delay test.
1. fix race between 'playing' and wakelock events.
2. remove the delay test per comment 4 ~ comment 8.

try: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=c7e7220078fc
I guess those oranges of test_ignoreuserfocus.html are not mine.
Assignee: nobody → jwwang
Status: NEW → ASSIGNED
Attachment #8501400 - Flags: review?(amarchesini)
Comment on attachment 8501400 [details] [diff] [review]
1023552_fix_test_audio_wakelock_html.patch

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

::: content/html/content/test/test_audio_wakelock.html
@@ +49,5 @@
> +      audio.pause();
> +      startDate = new Date();
> +      return;
> +    }
> +

is(count, 2, "The count should be 1 or 2 max"); // or a better message.
Attachment #8501400 - Flags: review?(amarchesini) → review+
Fix nits suggested by comment 15.
Attachment #8501400 - Attachment is obsolete: true
Attachment #8502207 - Flags: review+
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/883279fdc2c6
Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla35
Is this occurring again? The cause seems different though.
Sadly yes. After more than about half a year...

Below is the logs:

05:00:13 INFO - 16 INFO TEST-PASS | dom/html/test/test_audio_wakelock.html | #1 Audio element locked the target == cpu
05:00:13 INFO - 17 INFO TEST-PASS | dom/html/test/test_audio_wakelock.html | #1 Audio element locked the cpu
05:00:13 INFO - 18 INFO TEST-PASS | dom/html/test/test_audio_wakelock.html | #1 Audio element locked the target == cpu
05:00:13 INFO - 19 INFO TEST-PASS | dom/html/test/test_audio_wakelock.html | #1 Audio element unlocked the cpu
05:00:13 INFO - 20 INFO TEST-PASS | dom/html/test/test_audio_wakelock.html | The count should be 2 which indicates wakelock release
05:00:13 INFO - 21 INFO TEST-UNEXPECTED-FAIL | dom/html/test/test_audio_wakelock.html | #1 There was at least 200 milliseconds between the stop and the wakelock release - expected PASS

My last fix didn't change the logic of checking wake lock interval. So it should be something related to gecko code changes.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
No failure for a long time. Please file a new bug should it fail again in the future since the cause will probably be different.
Status: REOPENED → RESOLVED
Closed: 5 years ago4 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.