Intermittent test_peerConnection_capturedVideo.html | Test timed out. - expected PASS

RESOLVED FIXED in Firefox 36

Status

()

defect
RESOLVED FIXED
5 years ago
5 years ago

People

(Reporter: cbook, Assigned: pehrsons)

Tracking

({intermittent-failure})

Trunk
mozilla38
x86
Linux
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite +
qe-verify -

Firefox Tracking Flags

(firefox36 fixed, firefox37 fixed, firefox38 fixed, firefox-esr31 unaffected, b2g-v2.2 fixed, b2g-master fixed)

Details

()

Attachments

(4 attachments, 9 obsolete attachments)

1.48 KB, patch
roc
: review+
Details | Diff | Splinter Review
1.49 KB, patch
roc
: review+
Details | Diff | Splinter Review
2.74 KB, patch
roc
: review+
pehrsons
: feedback+
Details | Diff | Splinter Review
2.82 KB, patch
roc
: review+
Details | Diff | Splinter Review
Reporter

Description

5 years ago
Ubuntu VM 12.04 x64 mozilla-inbound debug test mochitest-3

https://treeherder.mozilla.org/logviewer.html#?job_id=4802458&repo=mozilla-inbound

02:23:49 INFO - 791 INFO TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_capturedVideo.html | Test timed out. - expected PASS
02:23:49 INFO - 843474688[7fba4a1b5ec0]: [|WebrtcAudioSessionConduit] AudioConduit.cpp:690: A/V sync: GetAVStats failed
02:23:49 INFO - 792 INFO TEST-OK | dom/media/tests/mochitest/test_peerConnection_capturedVideo.html | took 307220ms
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Regression from bug 879717 based on retriggers.
Blocks: 879717
Flags: needinfo?(pehrsons)
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Component: DOM → WebRTC: Audio/Video
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Assignee

Comment 9

5 years ago
I think this is happening because v1 ends before the PeerConnection has been established and been able to transmit the first frame. Before bug 879717 we'd progress the video element state without a video frame but now we depend on it.

If this is true we should be able to fix the issue by looping v1.
Flags: needinfo?(pehrsons)
Assignee

Comment 10

5 years ago
Oh, no, I don't think that's the case at all.

But this test uses vp9cake.webm for capturing and sending over the peerConnection - same as is failing playback in bug 1080685.
Assignee

Comment 11

5 years ago
I switched to using seek.webm (video only) instead of vp9cake.webm and it would time out every time. Turned out to be related to when mozCaptureStream() was called on the video element. Testing to see if it's the same issue here.

Early mozCaptureStream(): https://treeherder.mozilla.org/#/jobs?repo=try&revision=773c1765efd0
Early mozCaptureStream() with seek.webm: https://treeherder.mozilla.org/#/jobs?repo=try&revision=afeea2b7e422
Assignee

Comment 12

5 years ago
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #11)
> I switched to using seek.webm (video only) instead of vp9cake.webm and it
> would time out every time. Turned out to be related to when
> mozCaptureStream() was called on the video element. Testing to see if it's
> the same issue here.

Seems to be a timing issue indeed.
Assignee

Comment 13

5 years ago
It seems to be a combo of starting to capture the stream when the MediaDecoderStateMachine is already in state PLAYING and using the clock through GetCurrentTimeViaMediaStreamSync().
Assignee

Comment 14

5 years ago
We're not taking account of MediaDecoder::DecodedStreamData::mInitialTime when calculating the stream clock. Patches incoming.
Blocks: 938022
Assignee

Updated

5 years ago
Duplicate of this bug: 1103963
Assignee

Updated

5 years ago
Component: WebRTC: Audio/Video → Video/Audio
Assignee

Comment 17

5 years ago
I've done more debugging to figure this one out now. There are at least two issues that become evident when you try to start a video element capture in the middle of playback.

1. You may get into a kind of deadlock when capturing video only media because:
  * rendering the next frame depends on GetClock() to be greater than the start time of said frame.
  * progressing the stream clock depends on getting output from (thus input to) the stream.

2. Capturing mid-playback will involuntarily pause the captured media element by the same time that passed since playback started.
  * Per the docs of mPlayDuration:
>  814   // The amount of time we've spent playing already the media. The current
>  815   // playback position is therefore |Now() - mPlayStartTime +
>  816   // mPlayDuration|, which must be adjusted by mStartTime if used with media
>  817   // timestamps. Accessed on state machine and main threads. Access controlled
>  818   // by decoder monitor.
>  819   int64_t mPlayDuration;  
  * However the sync point ignores (Now() - mPlayStartTime()):
> mSyncPointInDecodedStream = mStartTime + mPlayDuration
Assignee

Comment 18

5 years ago
Fixes comment 17, point 1.
Attachment #8539726 - Attachment is obsolete: true
Assignee

Comment 20

5 years ago
I was calling the state machine from the main thread. Not sure why that didn't assert on my local build. Here's a fix nevertheless.
Attachment #8545848 - Attachment is obsolete: true
Assignee

Comment 21

5 years ago
Taking the opportunity to fix an assertion fixme since the stream clock should no longer go backwards after the part 2 patch. (knock on wood)
Assignee

Comment 22

5 years ago
Also adding a mochitest to avoid this in the future.
Assignee

Comment 24

5 years ago
Now it should work better. I had accidentally wiped my mozconfig so I was testing locally on a prod-build. Instead of trying to dispatch something from MediaDecoder, the StateMachine now checks if the decoded stream has been initialized yet (it gets initialized during SendStreamData()) and if not, sends stream data right away - not waiting for the next audio/video frame to become available (which depends on the the stream clock progressing).
Attachment #8545946 - Attachment is obsolete: true
Assignee

Comment 25

5 years ago
Making the test more robust. There's a risk short media finishes while we're initializing the element capturing, so needed some checks for that.
Attachment #8545950 - Attachment is obsolete: true
Assignee

Comment 27

5 years ago
Comment on attachment 8546423 [details] [diff] [review]
Part 4. Add mochitest for capturing media mid-playback

JW, do you mind looking through this test? Should be pretty self-explanatory.
Attachment #8546423 - Flags: feedback?(jwwang)
Comment on attachment 8546423 [details] [diff] [review]
Part 4. Add mochitest for capturing media mid-playback

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

::: dom/media/test/test_streams_element_capture_midplayback.html
@@ +8,5 @@
> +</head>
> +<body>
> +<pre id="test">
> +<script class="testbody" type="text/javascript">
> +SimpleTest.waitForExplicitFinish();

You don't need this line for manager.runTests() will do this for you.

@@ +17,5 @@
> +  var canvas = document.createElement("canvas");
> +  var ctx = canvas.getContext("2d");
> +  ctx.drawImage(vout, 0, 0);
> +  var imgData = ctx.getImageData(0, 0, 1, 1);
> +  is(imgData.data[3], 255, "Check video frame pixel has been drawn");

Why we expect the pixel value to be 255?

@@ +31,5 @@
> +  v.height = 120;
> +  var vout = document.createElement('video');
> +  vout.style = "background-color:#aac;";
> +  vout.width = 80;
> +  vout.height = 60;

Do these width/height/background color settings have special meanings?

@@ +56,5 @@
> +    vout.play();
> +  };
> +
> +  v.onended = function() {
> +    if (vout.readyState == vout.HAVE_NOTHING) {

I think this test should move to vout.onended. If v reaches the end, vout should also receive 'ended' event later on, right?
Attachment #8546423 - Flags: feedback?(jwwang)
Assignee

Comment 29

5 years ago
Comment on attachment 8546423 [details] [diff] [review]
Part 4. Add mochitest for capturing media mid-playback

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

The comment here might not make sense but it should look good on the review page.

::: dom/media/test/test_streams_element_capture_midplayback.html
@@ +8,5 @@
> +</head>
> +<body>
> +<pre id="test">
> +<script class="testbody" type="text/javascript">
> +SimpleTest.waitForExplicitFinish();

Oh, yes. I used another of the element_capture tests as a template - it must have this as well.

@@ +17,5 @@
> +  var canvas = document.createElement("canvas");
> +  var ctx = canvas.getContext("2d");
> +  ctx.drawImage(vout, 0, 0);
> +  var imgData = ctx.getImageData(0, 0, 1, 1);
> +  is(imgData.data[3], 255, "Check video frame pixel has been drawn");

It's the alpha channel and once a frame is drawn it will have changed from 0 to 255. Same as test_streams_element_capture.html and test_streams_element_capture_createObjectURL.html.

@@ +31,5 @@
> +  v.height = 120;
> +  var vout = document.createElement('video');
> +  vout.style = "background-color:#aac;";
> +  vout.width = 80;
> +  vout.height = 60;

No, purely to provide some visual aid when running the test locally.

@@ +56,5 @@
> +    vout.play();
> +  };
> +
> +  v.onended = function() {
> +    if (vout.readyState == vout.HAVE_NOTHING) {

I have seen cases where vout doesn't end. It appears to be when we're capturing the video element after playback has finished.

Since we're listening to ontimeupdate and waiting until 1/4 of the duration has passed the 'timeupdate' that satisfies this might actually be after the media ended.

Oh well, then the check should be in the ontimeupdate handler of course. Thanks ;-)
Assignee

Comment 30

5 years ago
This removes SimpleTest.waitForExplicitFinish() and v.onended per the comments above.
Attachment #8546423 - Attachment is obsolete: true
Attachment #8546493 - Flags: feedback?(jwwang)
Comment on attachment 8546423 [details] [diff] [review]
Part 4. Add mochitest for capturing media mid-playback

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

Looks find to me.

::: dom/media/test/test_streams_element_capture_midplayback.html
@@ +56,5 @@
> +    vout.play();
> +  };
> +
> +  v.onended = function() {
> +    if (vout.readyState == vout.HAVE_NOTHING) {

It seems a bug to me. Since we are capturing in the middle of playback, it is possible to capture a already ended element. What would it be if we assign this stream to vout? It can be addressed in another bug.
Attachment #8546423 - Attachment is obsolete: false
Attachment #8546423 - Flags: feedback+
Attachment #8546493 - Flags: feedback?(jwwang) → feedback+
Assignee

Comment 32

5 years ago
Comment on attachment 8546423 [details] [diff] [review]
Part 4. Add mochitest for capturing media mid-playback

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

::: dom/media/test/test_streams_element_capture_midplayback.html
@@ +56,5 @@
> +    vout.play();
> +  };
> +
> +  v.onended = function() {
> +    if (vout.readyState == vout.HAVE_NOTHING) {

Not sure what the expected behavior is for this case. Do you know?

We're not capturing in the middle of playback here though since it has already ended. Basically the chain of events looks like this:
* v ends and sets its ended property to true
* v fires timeupdate and we call v.mozCaptureStream
* v fires ended

I don't know if the stream ends or not here but if we later play this stream in another element it sounds reasonable to me to not get an "ended" event there.
Assignee

Updated

5 years ago
Attachment #8546423 - Attachment is obsolete: true
Assignee

Comment 33

5 years ago
Still got an intermittent failure with the new test on B2G in the last try (comment 26). Looks like a fun one.
Comment hidden (Legacy TBPL/Treeherder Robot)
Comment hidden (Legacy TBPL/Treeherder Robot)
Assignee

Comment 36

5 years ago
Comment 34 and 35 must be something else. This is just for when test_peerConnection_capturedVideo.html times out. Also only happens together with the bug 879717 patches :)
Flags: needinfo?(ryanvm)
Assignee

Comment 37

5 years ago
Simplifying the test quite a bit here - dropping all forms of checking for sane values.

When it would fail on top of bug 879717 we'd see a timeout because time stalled on the captured element. Now I'm just checking that we get the "ended" event for both the captured video element and the video element playing the stream.

This test reproduces the issue nicely if run without part 1 and 2.
Attachment #8546493 - Attachment is obsolete: true
Attachment #8547391 - Flags: feedback?(jwwang)
Assignee

Comment 38

5 years ago
Comment on attachment 8545949 [details] [diff] [review]
Part 3. Assert media clock not going backwards also for stream clock

This assertion went off a few times on B2G, so holding it off for now.

See https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=790712f9d23e, e.g., the 3rd M12.
Attachment #8545949 - Attachment is obsolete: true
Comment on attachment 8547391 [details] [diff] [review]
Part 3. Add mochitest for capturing media mid-playback

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

::: dom/media/test/test_bug1113600.html
@@ +44,5 @@
> +      // Allow some time to pass before starting the capture.
> +      return;
> +    }
> +    v.ontimeupdate = null;
> +    if (v.ended) {

I think you still need to handle the case where v.ended is false but the current playback position has reached the end on the state machine thread. So we should expect 'ended' event on both v and vout no matter when v is captured.
Assignee

Updated

5 years ago
Attachment #8547391 - Flags: feedback?(jwwang)
Assignee

Comment 40

5 years ago
I have simplified the test even further.

We don't need a vout to reproduce this. We just have a video element v and capture it when its time has progressed a little. If it fails per this bug, its clock will stall and it will never end. The test will time out.

If it ends we are golden.
Attachment #8547391 - Attachment is obsolete: true
Attachment #8547432 - Flags: feedback?(jwwang)
Comment on attachment 8547432 [details] [diff] [review]
Part 3. Add mochitest for capturing media mid-playback

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

Overall looks fine to me.

::: dom/media/test/test_bug1113600.html
@@ +27,5 @@
> +      return;
> +    }
> +    v.ontimeupdate = null;
> +    v.mozCaptureStreamUntilEnded();
> +    info(test.name + " capture started at " + v.captureStartTime + ". Duration=" + test.duration);

what is v.captureStartTime? Do you mean v.currentTime?

@@ +31,5 @@
> +    info(test.name + " capture started at " + v.captureStartTime + ". Duration=" + test.duration);
> +  };
> +
> +  v.onended = function() {
> +    ok(true, test.name + " did not stall");

The description is confusing with the 'stalled' event of the media element.
Attachment #8547432 - Flags: feedback?(jwwang) → feedback+
Assignee

Comment 42

5 years ago
(In reply to JW Wang [:jwwang] from comment #41)
> Comment on attachment 8547432 [details] [diff] [review]
> Part 3. Add mochitest for capturing media mid-playback
> 
> Review of attachment 8547432 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Overall looks fine to me.
> 
> ::: dom/media/test/test_bug1113600.html
> @@ +27,5 @@
> > +      return;
> > +    }
> > +    v.ontimeupdate = null;
> > +    v.mozCaptureStreamUntilEnded();
> > +    info(test.name + " capture started at " + v.captureStartTime + ". Duration=" + test.duration);
> 
> what is v.captureStartTime? Do you mean v.currentTime?

Wups, some legacy is still around.

> @@ +31,5 @@
> > +    info(test.name + " capture started at " + v.captureStartTime + ". Duration=" + test.duration);
> > +  };
> > +
> > +  v.onended = function() {
> > +    ok(true, test.name + " did not stall");
> 
> The description is confusing with the 'stalled' event of the media element.

Good point, will fix.
Assignee

Comment 43

5 years ago
Fixes per previous comment.
Attachment #8547432 - Attachment is obsolete: true
Attachment #8547465 - Flags: review?(roc)
Attachment #8547465 - Flags: feedback+
Assignee

Comment 44

5 years ago
Comment on attachment 8546422 [details] [diff] [review]
Part 1. Send stream data right away after adding an output stream

See comment 17 for the analysis behind this patch.
Attachment #8546422 - Flags: review?(roc)
Assignee

Comment 45

5 years ago
Comment on attachment 8545849 [details] [diff] [review]
Part 2. Handle setting a MediaStream sync point mid-playback

Again, see comment 17 for the analysis behind this patch.
Attachment #8545849 - Flags: review?(roc)
Assignee

Comment 46

5 years ago
Here's a try reflecting the state in comment 39: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=5afba98f6ba8

Doing it on all platforms to get some extra coverage on bug 879717 that I'm hoping to land on top of this one.

It seems like JW was right (as always) about the case where v.ended is false but the state machine thread is finished - see the B2G desktop orange.
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #36)
> Comment 34 and 35 must be something else. This is just for when
> test_peerConnection_capturedVideo.html times out. Also only happens together
> with the bug 879717 patches :)

From the logcat:
01-09 05:03:49.375 I/Gecko   ( 2255): [Parent 2255] ###!!! ASSERTION: Clock should go forwards if the playback rate is > 0.: 'GetMediaTime() <= clock_time || mPlaybackRate <= 0', file /builds/slave/fx-team-and-api-11-d-000000000/build/dom/media/MediaDecoderStateMachine.cpp, line 2915

Which is bug 1103963. Which you duped to this one.
Flags: needinfo?(ryanvm)
Assignee

Comment 49

5 years ago
(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #48)
> (In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #36)
> > Comment 34 and 35 must be something else. This is just for when
> > test_peerConnection_capturedVideo.html times out. Also only happens together
> > with the bug 879717 patches :)
> 
> From the logcat:
> 01-09 05:03:49.375 I/Gecko   ( 2255): [Parent 2255] ###!!! ASSERTION: Clock
> should go forwards if the playback rate is > 0.: 'GetMediaTime() <=
> clock_time || mPlaybackRate <= 0', file
> /builds/slave/fx-team-and-api-11-d-000000000/build/dom/media/
> MediaDecoderStateMachine.cpp, line 2915
> 
> Which is bug 1103963. Which you duped to this one.

Yeah you're right. I thought that came from the same cause as here, thus not yet in prod. However, judging from your findings and my latest try it either doesn't or I missed something.
Assignee

Comment 50

5 years ago
The cause behind bug 1103963 is related enough to this that I want to fix it here.

See bug 1103963 comment 14 for the analysis. In short we'd, mostly on Android - also seen on B2G, starve out the state machine enough so instead of switching from audio -> system -> stream clock like on most platforms we'd go from audio -> stream clock directly. This had the downside of skipping the ResyncAudioClock() call, thus setting time back a little (we always sync the stream clock to the system clock).

I'm also taking the opportunity (again) to remove that FIXME and enabling an assertion in MediaDecoderStateMachine.
Attachment #8547780 - Flags: review?(roc)
Assignee

Comment 51

5 years ago
Here's my latest wip try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=b470f97f8b48

It's orange now but that's actually because of a bad printf_stderr and can be ignored.


This try will hopefully become green shortly: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=6e58e2f736ac
Comment on attachment 8545849 [details] [diff] [review]
Part 2. Handle setting a MediaStream sync point mid-playback

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

We should rename mPlayStartTime to mLastPlayStartTime at some point...
Attachment #8545849 - Flags: review?(roc) → review+
Comment on attachment 8547780 [details] [diff] [review]
Part 4. Handle switching directly from audio clock to stream clock

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

You are awesome.
Attachment #8547780 - Flags: review?(roc) → review+
Comment on attachment 8547780 [details] [diff] [review]
Part 4. Handle switching directly from audio clock to stream clock

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

::: dom/media/MediaDecoderStateMachine.cpp
@@ +1343,5 @@
>      // If mStopAudioThread is true then we're already stopping the audio sink
>      // and since we set mAudioCaptured to true, nothing can start it again.
>      ScheduleStateMachine();
> +
> +    if (HasAudio()) {

I thought about that before but I found it unnecessary since audio capture will stop audio thread which will call MediaDecoderStateMachine::OnAudioSinkComplete() which in turn will call ResyncAudioClock(). What did I miss?
Assignee

Comment 55

5 years ago
(In reply to JW Wang [:jwwang] from comment #54)
> Comment on attachment 8547780 [details] [diff] [review]
> Part 4. Handle switching directly from audio clock to stream clock
> 
> Review of attachment 8547780 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: dom/media/MediaDecoderStateMachine.cpp
> @@ +1343,5 @@
> >      // If mStopAudioThread is true then we're already stopping the audio sink
> >      // and since we set mAudioCaptured to true, nothing can start it again.
> >      ScheduleStateMachine();
> > +
> > +    if (HasAudio()) {
> 
> I thought about that before but I found it unnecessary since audio capture
> will stop audio thread which will call
> MediaDecoderStateMachine::OnAudioSinkComplete() which in turn will call
> ResyncAudioClock(). What did I miss?

What I observed is that we'd SetSyncPointForMediaStream() before OnAudioSinkComplete() in the failure case. I never fully understood why, but I assume scheduling.
Assignee

Comment 56

5 years ago
Please also land bug 879717 on top of this.
Keywords: checkin-needed
Assignee

Comment 57

5 years ago
Summary of the tries supporting this landing:

Before Part 4 here: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=8c002211860c
After: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=6e58e2f736ac

We can see bug 1113717 still occurring on Mulet, plus I see one occurrence of test_peerConnection_capturedVideo.html timing out on linux debug.

The frequency is low on both though, I'll fix them as we go along.
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #55)
> What I observed is that we'd SetSyncPointForMediaStream() before
> OnAudioSinkComplete() in the failure case. I never fully understood why, but
> I assume scheduling.

HTMLMediaElement::CaptureStreamInternal {
  [1] MediaDecoder::SetAudioCaptured -> MediaDecoderStateMachine::SetAudioCaptured
  [2] MediaDecoder::AddOutputStream -> MediaDecoder::RecreateDecodedStream -> MediaDecoder::UpdateStreamBlockingForStateMachinePlaying -> MediaDecoderStateMachine::SetSyncPointForMediaStream
}

Reading |mPlayDuration| in MediaDecoderStateMachine::SetSyncPointForMediaStream() would be wrong without re-sync audio clock. That is what you observed.

I think MediaDecoderStateMachine::SetSyncPointForMediaStream() should happen after AudioSink is completely finished. Otherwise, there will be some audio samples which are played by AudioSink but not counted into |mPlayDuration|. The stream time (near the end) will be inaccurate.

However, that shouldn't be a problem. When you capture in the middle of playback, you can never know the precise time when the capture takes effect.

But, it could be a problem that ResyncAudioClock() happens again in OnAudioSinkComplete() despite it is done already in SetAudioCaptured().
Assignee

Comment 60

5 years ago
Thanks for a pair of fresh eyes on this JW. I filed bug 1120818 as a followup.

Some comments inline though,

(In reply to JW Wang [:jwwang] from comment #59)
> (In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #55)
> > What I observed is that we'd SetSyncPointForMediaStream() before
> > OnAudioSinkComplete() in the failure case. I never fully understood why, but
> > I assume scheduling.
> 
> HTMLMediaElement::CaptureStreamInternal {
>   [1] MediaDecoder::SetAudioCaptured ->
> MediaDecoderStateMachine::SetAudioCaptured
>   [2] MediaDecoder::AddOutputStream -> MediaDecoder::RecreateDecodedStream
> -> MediaDecoder::UpdateStreamBlockingForStateMachinePlaying ->
> MediaDecoderStateMachine::SetSyncPointForMediaStream
> }

One bit I don't fully comprehend here is:

void MediaDecoderStateMachine::OnAudioSinkComplete()
{
  AssertCurrentThreadInMonitor();
  if (mAudioCaptured) {
    return;
  }
  ResyncAudioClock();
  (...)
}

And as you noted we start CaptureStreamInternal by
MediaDecoderStateMachine::SetAudioCaptured() {
  [1] MediaDecoderStateMachine::ScheduleStateMachine();
  [2] MediaDecoderStateMachine::mAudioCaptured = aCaptured;
}

I don't understand how OnAudioSinkComplete gets scheduled so quickly. It seems more natural that mAudioCaptured becomes true before the StateMachine's next run, then ResyncAudioClock() won't be called at all.

> Reading |mPlayDuration| in
> MediaDecoderStateMachine::SetSyncPointForMediaStream() would be wrong
> without re-sync audio clock. That is what you observed.
> 
> I think MediaDecoderStateMachine::SetSyncPointForMediaStream() should happen
> after AudioSink is completely finished. Otherwise, there will be some audio
> samples which are played by AudioSink but not counted into |mPlayDuration|.
> The stream time (near the end) will be inaccurate.
> 
> However, that shouldn't be a problem. When you capture in the middle of
> playback, you can never know the precise time when the capture takes effect.
> 
> But, it could be a problem that ResyncAudioClock() happens again in
> OnAudioSinkComplete() despite it is done already in SetAudioCaptured().

It won't, as it will get caught by the
if (mAudioCaptured) {
  return;
}

If it would run twice, we'd see mPlayStartTime and mPlayDuration being overwritten with new values. MediaDecoderStateMachine::GetCurrentTimeViaMediaStreamSync() doesn't depend on any of them though, so shouldn't that be fine?
Assignee

Updated

5 years ago
Blocks: 1120818
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #60)
> It won't, as it will get caught by the
> if (mAudioCaptured) {
>   return;
> }

Yeah, you are right.

> If it would run twice, we'd see mPlayStartTime and mPlayDuration being
> overwritten with new values.
> MediaDecoderStateMachine::GetCurrentTimeViaMediaStreamSync() doesn't depend
> on any of them though, so shouldn't that be fine?

GetCurrentTimeViaMediaStreamSync() depends on |mSyncPointInDecodedStream| which depends on |mPlayDuration| which depends on when ResyncAudioClock() happens.
We're going to want to get this on Aurora37 too given that the uplift was yesterday. I don't think we need to worry about this for Beta36 or any older B2G releases, though?
Assignee

Comment 64

5 years ago
Comment on attachment 8546422 [details] [diff] [review]
Part 1. Send stream data right away after adding an output stream

Approval Request Comment
[Feature/regressing bug #]: Bug 938022 (part 6)
[User impact if declined]: calling mozCaptureStream() on a media element that is already playing may pause it involuntarily, with no chance of recovery.
[Describe test coverage new/current, TBPL]: Dedicated mochitest
[Risks and why]: low
[String/UUID change made/needed]: none
Attachment #8546422 - Flags: approval-mozilla-aurora?
Assignee

Comment 65

5 years ago
Comment on attachment 8545849 [details] [diff] [review]
Part 2. Handle setting a MediaStream sync point mid-playback

See comment 64
Attachment #8545849 - Flags: approval-mozilla-aurora?
Assignee

Comment 66

5 years ago
Comment on attachment 8547780 [details] [diff] [review]
Part 4. Handle switching directly from audio clock to stream clock

See comment 64.

And with part 3 being testonly it's ok to not request uplift I take it.
Attachment #8547780 - Flags: approval-mozilla-aurora?
For future reference, you can just request approval on the first patch with a comment that it's for all patches in the bug :)
Assignee

Updated

5 years ago
Duplicate of this bug: 1103963
(In reply to Ryan VanderMeulen [:RyanVM UTC-5] from comment #67)
> For future reference, you can just request approval on the first patch with
> a comment that it's for all patches in the bug :)

I actually prefer to have the approval flag set on all of the patches so that none get missed.
Unfortunately we don't have that established as a consistent practice anywhere.
Nor does that really allow for the bustage follow-ups and the like which never show up in a bug as attachments.
Comment on attachment 8546422 [details] [diff] [review]
Part 1. Send stream data right away after adding an output stream

Aurora+

I'm happy to take the test too unless there is a reason not to.
Flags: needinfo?(pehrsons)
Attachment #8546422 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Attachment #8545849 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Attachment #8547780 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Assignee

Comment 73

5 years ago
Comment on attachment 8547465 [details] [diff] [review]
Part 3. Add mochitest for capturing media mid-playback (carries f=jwwang)

(In reply to Lawrence Mandel [:lmandel] (use needinfo) from comment #72)
> Comment on attachment 8546422 [details] [diff] [review]
> Part 1. Send stream data right away after adding an output stream
> 
> Aurora+
> 
> I'm happy to take the test too unless there is a reason not to.

Sure, go ahead. I was thinking it is not necessary because a=testonly is allowed anyway, but am unaware of the customs here. :)
Flags: needinfo?(pehrsons)
Attachment #8547465 - Flags: approval-mozilla-aurora?
Assignee

Comment 74

5 years ago
Beta is also affected.
Assignee

Comment 75

5 years ago
Comment on attachment 8546422 [details] [diff] [review]
Part 1. Send stream data right away after adding an output stream

See comment 64 for the approval request comment.

While I didn't for aurora, I'll let this be a request for approval of all the patches on this bug. Sorry for any confusion.
Attachment #8546422 - Flags: approval-mozilla-beta?
Attachment #8546422 - Flags: approval-mozilla-b2g37?
Attachment #8546422 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Assignee

Updated

5 years ago
Attachment #8546422 - Flags: approval-mozilla-b2g37?
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #73)
> Sure, go ahead. I was thinking it is not necessary because a=testonly is
> allowed anyway, but am unaware of the customs here. :)

I misread your comment as suggesting that we shouldn't uplift the test. You're right that tests can be uplifted with a=testonly. In practice, for bugs that have changes that impact the product as well as tests, I typically just add approval to the tests at the same time as the rest of the code change.
Attachment #8547465 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Flags: qe-verify-
Blocks: 1124404
Assignee

Updated

5 years ago
Depends on: 1106963
You need to log in before you can comment on or make changes to this bug.