Closed Bug 1392945 Opened 7 years ago Closed 4 years ago

Intermittent dom/media/test/test_mediarecorder_playback_can_repeat.html | Test timed out.

Categories

(Core :: Audio/Video: Playback, defect, P5)

Product:
Core
Component:
Audio/Video: Playback
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla73
Tracking Flags:
Tracking Status
firefox-esr68 --- fixed
firefox71 --- wontfix
firefox72 --- wontfix
firefox73 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: pehrsons)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Attachments

(1 file)

Bug 1392945 - Wait for "seeked" instead of "playing". r?alwu
47 bytes, text/x-phabricator-request
Details | Review
Flags: needinfo?(alwu)
Since its failure rate is super low, I think it's not worth to spend time investigating it. I'll prefer to wait for a long while to see its trend (still happen or disappear).
Flags: needinfo?(alwu)
Re-triaging per https://bugzilla.mozilla.org/show_bug.cgi?id=1473195

Needinfo :susheel if you think this bug should be re-triaged.

This bug failed 33 times in the last 7 days. Occurs on macosx1014-64 and macosx1014-64-shippable on debug and opt build types.

Log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=277483272&repo=mozilla-central&lineNumber=6544

This has 115 total failures in the last 30 days and it only fails on mac debug and opt. It's disabled on (os == 'win' && os_version == '10.0' && webrender). Jean-Yves, being the triage owner for this could you please take a look over it and maybe assign it to someone? Thank you.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=278946111&repo=autoland&lineNumber=6884

Flags: needinfo?(jyavenard)
Whiteboard: [stockwell needswork:owner]

Andreas, is this something you're familiar with?

Flags: needinfo?(jyavenard) → needinfo?(apehrson)

Looking at a recent log of this, the recording is fine but we time out when playing it back with the loop attribute.

In particular, we see one "playing" event but expect more; one for each time the loop attribute seeks back to the beginning. It seems in the spec like these "playing" events are guaranteed if the loop-seek causes the readyState to go back to HAVE_CURRENT_DATA. Do you know if this is guaranteed?

Flags: needinfo?(apehrson) → needinfo?(jyavenard)

Most failures nowadays are on macosx10.14 fwiw. These are some mac minis that have fewer cores than the linux based tryserver hosts IIRC.

Component: Audio/Video → Audio/Video: Playback
Product: Firefox for Android → Core

(In reply to Andreas Pehrson [:pehrsons] from comment #36)

Looking at a recent log of this, the recording is fine but we time out when playing it back with the loop attribute.

In particular, we see one "playing" event but expect more; one for each time the loop attribute seeks back to the beginning. It seems in the spec like these "playing" events are guaranteed if the loop-seek causes the readyState to go back to HAVE_CURRENT_DATA. Do you know if this is guaranteed?

playing is fired whenever the step "notify about playing" is called.
This occurs when we move from HAVE_CURRENT_DATA to either HAVE_FUTURE_DATA or HAVE_ENOUGH_DATA provided the paused attribute was false.
https://html.spec.whatwg.org/multipage/media.html#ready-states:notify-about-playing

Now with the loop attribute, when playback reaches the end, it will seek to the beginning of the media.

Now where it gets confusing is that the spec states that readyState is to move to HAVE_CURRENT_DATA if we have reached the end of the element.
https://html.spec.whatwg.org/multipage/media.html#dom-media-have_current_data
"or there is no more data to obtain in the direction of playback. For example, in video this corresponds to the user agent having data from the current frame, but not the next frame, when the current playback position is at the end of the current frame; and to when playback has ended."

But we are looping, so has playback ended really? We've done some work in particular so that looping would be gapless with audio playback. As such, I wouldn't expect readyState to change.

So if we are playing and in a loop, and going back to the start, I'm not sure if the readyState should be moved back to HAVE_CURRENT_DATA.

We used to, upon seeking immediately move the readyState to HAVE_METADATA, and IIRC there are WPT test checking that it is indeed the case.
readyState (for MSE at least) is based on the buffered range. For standard playback, the status of the current frame is decided by the MediaDecoderStateMachine when it has actually decoded a frame.

So in all, I don't think we can reliably assume that a playing event will fire, as this would assume we always move back to HAVE_CURRENT_DATA or lower.

TBH now, my memory is a bit fuzzy on the various implementation details. Especially now that the MDSM has moved to a state table, it makes it harder to follow the code to find out what it is we are doing.

:alwu, what do you think on that?

Flags: needinfo?(jyavenard) → needinfo?(alwu)

(In reply to Jean-Yves Avenard [:jya] from comment #38)

(In reply to Andreas Pehrson [:pehrsons] from comment #36)

Looking at a recent log of this, the recording is fine but we time out when playing it back with the loop attribute.

In particular, we see one "playing" event but expect more; one for each time the loop attribute seeks back to the beginning. It seems in the spec like these "playing" events are guaranteed if the loop-seek causes the readyState to go back to HAVE_CURRENT_DATA. Do you know if this is guaranteed?

playing is fired whenever the step "notify about playing" is called.
This occurs when we move from HAVE_CURRENT_DATA to either HAVE_FUTURE_DATA or HAVE_ENOUGH_DATA provided the paused attribute was false.
https://html.spec.whatwg.org/multipage/media.html#ready-states:notify-about-playing

Now with the loop attribute, when playback reaches the end, it will seek to the beginning of the media.

Now where it gets confusing is that the spec states that readyState is to move to HAVE_CURRENT_DATA if we have reached the end of the element.
https://html.spec.whatwg.org/multipage/media.html#dom-media-have_current_data
"or there is no more data to obtain in the direction of playback. For example, in video this corresponds to the user agent having data from the current frame, but not the next frame, when the current playback position is at the end of the current frame; and to when playback has ended."

But we are looping, so has playback ended really?

Definitely not, because if the direction is forwards, playback has ended when:

  • The current playback position is the end of the media resource, and
  • The media element does not have a loop attribute specified.

We've done some work in particular so that looping would be gapless with audio playback. As such, I wouldn't expect readyState to change.

So if we are playing and in a loop, and going back to the start, I'm not sure if the readyState should be moved back to HAVE_CURRENT_DATA.

We used to, upon seeking immediately move the readyState to HAVE_METADATA, and IIRC there are WPT test checking that it is indeed the case.
readyState (for MSE at least) is based on the buffered range. For standard playback, the status of the current frame is decided by the MediaDecoderStateMachine when it has actually decoded a frame.

So in all, I don't think we can reliably assume that a playing event will fire, as this would assume we always move back to HAVE_CURRENT_DATA or lower.

TBH now, my memory is a bit fuzzy on the various implementation details. Especially now that the MDSM has moved to a state table, it makes it harder to follow the code to find out what it is we are doing.

:alwu, what do you think on that?

Thanks for the input jya. By spec I think guaranteeing HAVE_CURRENT_DATA on loop-seek comes down to whether we have the beginning of the file buffered or not. How this looks in our impl I don't know.

Changing the test seems like a reasonable thing. Listening for "seeked" instead of "playing" seems like a good choice here.

Assignee: nobody → apehrson
Status: NEW → ASSIGNED

Yes, I don't think we can guarantee receiving playing twice, listening seeked would be better. MDSM would handle looping automatically, so MediaElement won't be aware of either reaching to the end or playing from the head again.

In addition, the ready state is controlled by the mBuffered in MFR, and it might be dropping down a little bit while we're seeking to the head, because seeking would reset the demuxer and clear its buffer, we still have enough data in the MDSM's queue though.

So, maybe the problem is because buffering is based on the buffer status of demuxer, not based on MDSN's. That causes ready state moving to lower state?

Flags: needinfo?(alwu)
Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/4805e7e3acb4
Wait for "seeked" instead of "playing". r=alwu

https://hg.mozilla.org/mozilla-central/rev/4805e7e3acb4

Status: ASSIGNED → RESOLVED
Closed: 4 years ago
status-firefox73: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla73
Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][checkin-needed-beta]
Whiteboard: [stockwell needswork:owner][checkin-needed-beta] → [stockwell needswork:owner]

== Change summary for alert #24302 (as of Fri, 06 Dec 2019 21:00:15 GMT) ==

Improvements:

57% raptor-tp6m-cnn-geckoview-cold loadtime android-hw-g5-7-0-arm7-api-16 pgo 14,311.17 -> 6,125.67
26% raptor-tp6m-cnn-geckoview-cold android-hw-g5-7-0-arm7-api-16 pgo 4,560.85 -> 3,357.70
18% raptor-tp6m-cnn-geckoview-cold fcp android-hw-g5-7-0-arm7-api-16 pgo 7,610.58 -> 6,224.92

For up to date results, see: https://treeherder.mozilla.org/perf.html#/alerts?id=24302

comment 45 seems.. rather unlikely for a test-only change.

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: