899935 - Stopping the MediaRecorder does not recieve a TRACK_EVENT_ENDED event from callback

Status: VERIFIED FIXED

(Core :: Audio/Video: Recording, defect)

Description

[Shelly Lin [:shelly]]

When stopping the MediaRecorder, MediaEncoder fail to recieve the event of TRACK_EVENT_ENDED from NotifyQueuedTrackChanges().

For more details:
Stops the MediaRecorder also removes its MediaEncoder from the TrackUnionStream:
http://dxr.mozilla.org/mozilla-central/source/content/media/MediaRecorder.cpp#l224

theoretically, the TrackUnionStream should issue the call of NotifyQueuedTrackChanges() from EndTrack():
http://dxr.mozilla.org/mozilla-central/source/content/media/TrackUnionStream.h#l180

Oberve:
MediaEncoder only reieves the callback of NotifyRemoved()

Comment 1

[Shelly Lin [:shelly]]

Attachment: Testcase

Comment 2

[Shelly Lin [:shelly]]

Attachment: GDB breakpoints

Comment 3

[Shelly Lin [:shelly]]

Requesting the gUM of mic adds a TrackUnionStream to the Graph, and DOMMediaStream::StreamListener will notify a TRACK_EVENT_CREATED event.

Starting the recorder adds another TrackUnionStream to the Graph, and MediaEncoder will notify a TRACK_EVENT_CREATED event.

If I stop the recorder, TrackUnionStream::EndTrack() is not called thus TRACK_EVENT_ENDED event is not notified.

If I close the tab while recording, DOMMediaStream::StreamListener fires the TRACK_EVENT_ENDED event and then MediaEncoder fires the TRACK_EVENT_ENDED event.

Hi Rob, does this sound normal? Or this is something that should take care of?

Comment 4

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

MediaRecorder::Stop isn't doing anything to trigger a TRACK_EVENT_ENDED. Instead of removing the listener immediately, I think you should call mStreamPort->Remove to disconnect the input stream. This will cause TRACK_EVENT_ENDED to fire.

Comment 5

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

It looks like we have a problem if someone does start(), stop() and then start() again. The problem is that the first mTrackUnionStream will not get Destroy() called on it and then the second start() will create a new mTrackUnionStream object, so mTrackUnionStream->Destroy() will never get called and we leak. Similar problem for mStreamPort.

A deeper problem is that if someone calls stop() and then immediately start(), we effectively have two overlapping recordings going on, because the operations on the original MediaStreams won't stop immediately. So for example, the first encoder will keep running for a while even after the second start() call is running. And our code can't handle that.

I think we need to create an object that represents a single recording ... maybe call it MediaRecorderSession? Most of the data and logic currently in MediaRecorder would move to MediaRecorderSession: mReadThread, mEncoder, mStream, mTrackUnionStream, mStreamPort, mEncodedBufferCache, mMimeType, mTimeSlice. The MediaRecorder would keep a list of the active MediaRecorderSessions, and the first element of the list would be the "current session" if the state is not "inactive". When the stop event has fired for a MediaRecorderSession, we can remove it from the list.

Make sense?

Comment 6

[Shelly Lin [:shelly]]

(In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #4)
> MediaRecorder::Stop isn't doing anything to trigger a TRACK_EVENT_ENDED.
> Instead of removing the listener immediately, I think you should call
> mStreamPort->Remove to disconnect the input stream. This will cause
> TRACK_EVENT_ENDED to fire.

I see, removing the listener doesn't end the track, destroying the stream does, so not receiving the TRACK_EVENT_ENDED event is actually as designed.

Comment 7

[Shelly Lin [:shelly]]

(In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #5)
> It looks like we have a problem if someone does start(), stop() and then
> start() again. The problem is that the first mTrackUnionStream will not get
> Destroy() called on it and then the second start() will create a new
> mTrackUnionStream object, so mTrackUnionStream->Destroy() will never get
> called and we leak. Similar problem for mStreamPort.
> 
Hmm, I think we should destroy the mTrackUnionStraem and mStramPort in Stop().

> A deeper problem is that if someone calls stop() and then immediately
> start(), we effectively have two overlapping recordings going on, because
> the operations on the original MediaStreams won't stop immediately. So for
> example, the first encoder will keep running for a while even after the
> second start() call is running. And our code can't handle that.
> 
> I think we need to create an object that represents a single recording ...
> maybe call it MediaRecorderSession? Most of the data and logic currently in
> MediaRecorder would move to MediaRecorderSession: mReadThread, mEncoder,
> mStream, mTrackUnionStream, mStreamPort, mEncodedBufferCache, mMimeType,
> mTimeSlice. The MediaRecorder would keep a list of the active
> MediaRecorderSessions, and the first element of the list would be the
> "current session" if the state is not "inactive". When the stop event has
> fired for a MediaRecorderSession, we can remove it from the list.
> 
> Make sense?
Yeah, this might be a better solution of handling stop/start recording, also, I've commented in bug 903758, the way of setting recorder::state to inactive at Stop() might result in a lost of last couple pages generated by OggWriter.

Comment 8

[Randy Lin [:rlin] - Be Mozillian on 2015/01/26]

The MediaRecorderSession also make sense to me. We can start to refactor the MediaRecorder object when implement the video recording function.

Comment 9

[Shelly Lin [:shelly]]

Attachment: Destroy the port and stream in Stop()

Please find my comments in the code review, thanks.

Comment 10

[Shelly Lin [:shelly]]

Comment on attachment 795965 [details] [diff] [review]
Destroy the port and stream in Stop()

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

::: content/media/MediaRecorder.cpp
@@ +87,5 @@
>        : mRecorder(recorder) {}
>  
>      NS_IMETHODIMP Run()
>      {
>        MOZ_ASSERT(NS_IsMainThread());

mState is set to Inactive at Stop().

@@ +152,5 @@
>      if (mTimeSlice > 0 && (TimeStamp::Now() - lastBlobTimeStamp).ToMilliseconds() > mTimeSlice) {
>        NS_DispatchToMainThread(new PushBlobTask(this));
>        lastBlobTimeStamp = TimeStamp::Now();
>      }
> +  } while (!mEncoder->IsShutdown());

Remove |mState == RecordingState::Recording| because one it stops the recorder from extracting encoded data while encoder hasn't finish encoding, and two we shouldn't access the mState outside the main thread.

@@ +232,5 @@
> +  mStreamPort->Destroy();
> +  mStreamPort = nullptr;
> +
> +  mTrackUnionStream->Destroy();
> +  mTrackUnionStream = nullptr;

The second call of Start() creates new object of port and stream, and we have leaks here if we fail to destroy the previous port and stream.

Comment 11

[Jason Smith [:jsmith]]

This needs to include a mochitest btw. See the blocking bug as an example of STR you could use to write a test.

Comment 12

[Shelly Lin [:shelly]]

I've tested it with "test_mediarecorder_record_no_timeslice.html" in the current m-c, should I test it with the attach like from bug 902318?

Comment 13

[Shelly Lin [:shelly]]

link*

This one below:
https://bug899878.bugzilla.mozilla.org/attachment.cgi?id=786738

Comment 14

[Jason Smith [:jsmith]]

(In reply to Shelly Lin [:shelly] from comment #12)
> I've tested it with "test_mediarecorder_record_no_timeslice.html" in the
> current m-c, should I test it with the attach like from bug 902318?

Yup. I'd include the patch from https://bug899878.bugzilla.mozilla.org/attachment.cgi?id=786738 with this patch so that it comes with a test.

Comment 15

[Jason Smith [:jsmith]]

(In reply to Jason Smith [:jsmith] from comment #14)
> (In reply to Shelly Lin [:shelly] from comment #12)
> > I've tested it with "test_mediarecorder_record_no_timeslice.html" in the
> > current m-c, should I test it with the attach like from bug 902318?
> 
> Yup. I'd include the patch from
> https://bug899878.bugzilla.mozilla.org/attachment.cgi?id=786738 with this
> patch so that it comes with a test.

You'll probably need to change the name of the test though - given that something is already in the tree with that mochitest name.

Comment 16

[Shelly Lin [:shelly]]

Comment on attachment 795965 [details] [diff] [review]
Destroy the port and stream in Stop()

Need more revise.

Comment 17

[Shelly Lin [:shelly]]

Attachment: Handle the immediate Stop after a Start call of MediaRecorder

Comment 18

[Shelly Lin [:shelly]]

Comment on attachment 796471 [details] [diff] [review]
Handle the immediate Stop after a Start call of MediaRecorder

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

::: content/media/MediaRecorder.cpp
@@ +157,5 @@
>      if (mTimeSlice > 0 && (TimeStamp::Now() - lastBlobTimeStamp).ToMilliseconds() > mTimeSlice) {
>        NS_DispatchToMainThread(new PushBlobTask(this));
>        lastBlobTimeStamp = TimeStamp::Now();
>      }
> +  } while (!mEncoder->IsShutdown());

Remove |mState == RecordingState::Recording| because one it stops the recorder from extracting encoded data while encoder hasn't finish encoding, and two we shouldn't access the mState outside the main thread.

@@ +237,5 @@
> +  mStreamPort->Destroy();
> +  mStreamPort = nullptr;
> +
> +  mTrackUnionStream->Destroy();
> +  mTrackUnionStream = nullptr;

The second call of Start() creates new object of port and stream, and we have leaks here if we fail to destroy the previous port and stream.

::: content/media/encoder/TrackEncoder.cpp
@@ +89,5 @@
> +      Init(DEFAULT_CHANNELS, DEFAULT_SAMPLING_RATE);
> +      mRawSegment->AppendNullData(mSilentDuration);
> +      mSilentDuration = 0;
> +    } else {
> +      NotifyCancel();

If someone calls a Stop right after calling Start of MediaRecorder, its track union stream is destroyed and removed immediately from the media graph. As a result, NotifyQueuedTrackChanges of MediaEncoder is never called and AudioTrackEncoder is never initialized nor receives any segment. In this case, we should cancel the encoder and notify any waited monitor.

Comment 19

[Shelly Lin [:shelly]]

Attachment: Mochitest test case

Hey Jason, this is the test case from
https://bug899878.bugzilla.mozilla.org/attachment.cgi?id=786738
except that I've removed the check of zero blob size. Zero blob size is as expected in this case.

Comment 20

[Jason Smith [:jsmith]]

Comment on attachment 796479 [details] [diff] [review]
Mochitest test case

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

review- only cause there's some updating you need to do for this new bug. The commit message isn't right, comments out of date, and we should checking blob size = 0.

::: content/media/test/test_mediarecorder_record_immediate_stop.html
@@ +12,5 @@
> +var manager = new MediaTestManager;
> +
> +/**
> + * Starts a test on every media recorder file included to check that a
> + * stream derived from the file can be recorded with no time slice provided.

This comment is old. We need to update this to what this is aiming to test.

@@ +55,5 @@
> +  };
> +
> +  // This handler verifies that only a single ondataavailable event handler
> +  // is fired with the blob generated having greater than zero size
> +  // and a correct mime type.

Nit - comment is out of date

@@ +65,5 @@
> +
> +      ok(evt instanceof BlobEvent,
> +         'Events fired from ondataavailable should be BlobEvent');
> +      is(evt.type, 'dataavailable',
> +         'Event type should dataavailable');

If we're expecting the blob size to be zero in this case, then we should check that it's zero, not remove the blob size check.

@@ +66,5 @@
> +      ok(evt instanceof BlobEvent,
> +         'Events fired from ondataavailable should be BlobEvent');
> +      is(evt.type, 'dataavailable',
> +         'Event type should dataavailable');
> +      

Nit - trailing whitespace

Comment 21

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

Comment on attachment 796471 [details] [diff] [review]
Handle the immediate Stop after a Start call of MediaRecorder

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

::: content/media/MediaRecorder.cpp
@@ +89,5 @@
>      NS_IMETHODIMP Run()
>      {
>        MOZ_ASSERT(NS_IsMainThread());
> +      mRecorder->mReadThread->Shutdown();
> +      mRecorder->mReadThread = nullptr;

If we get a Start(), Stop(), Start() sequence, then this could shut down mReadThread while it's being used by a different encoder.

I don't think we can really fix this bug without doing the MediaRecorderSession idea.

::: content/media/encoder/TrackEncoder.cpp
@@ +89,5 @@
> +      Init(DEFAULT_CHANNELS, DEFAULT_SAMPLING_RATE);
> +      mRawSegment->AppendNullData(mSilentDuration);
> +      mSilentDuration = 0;
> +    } else {
> +      NotifyCancel();

I don't think we should do this. I think we should produce a zero-length output.

Comment 22

[Shelly Lin [:shelly]]

Attachment: Handle the immediate Stop after a Start call of MediaRecorder

Comment 23

[Shelly Lin [:shelly]]

(In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #21)
> Comment on attachment 796471 [details] [diff] [review]
> Handle the immediate Stop after a Start call of MediaRecorder
> 
> Review of attachment 796471 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: content/media/MediaRecorder.cpp
> @@ +89,5 @@
> >      NS_IMETHODIMP Run()
> >      {
> >        MOZ_ASSERT(NS_IsMainThread());
> > +      mRecorder->mReadThread->Shutdown();
> > +      mRecorder->mReadThread = nullptr;
> 
> If we get a Start(), Stop(), Start() sequence, then this could shut down
> mReadThread while it's being used by a different encoder.
> 
> I don't think we can really fix this bug without doing the
> MediaRecorderSession idea.
> 
No, this won't fix the Start(), Stop(), Start() issue, it is for the case where someone calls Start() in the onstop() callback, this at least ensure the mReadThread is shut down. I've file a bug for MediaRecorderSession (bug 909640).

> ::: content/media/encoder/TrackEncoder.cpp
> @@ +89,5 @@
> > +      Init(DEFAULT_CHANNELS, DEFAULT_SAMPLING_RATE);
> > +      mRawSegment->AppendNullData(mSilentDuration);
> > +      mSilentDuration = 0;
> > +    } else {
> > +      NotifyCancel();
> 
> I don't think we should do this. I think we should produce a zero-length
> output.
Changed in the new patch.

Comment 24

[Shelly Lin [:shelly]]

(In reply to Shelly Lin [:shelly] from comment #23)
> (In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #21)
> > Comment on attachment 796471 [details] [diff] [review]
> > Handle the immediate Stop after a Start call of MediaRecorder
> > 
> > Review of attachment 796471 [details] [diff] [review]:
> > -----------------------------------------------------------------
> > 
> > ::: content/media/MediaRecorder.cpp
> > @@ +89,5 @@
> > >      NS_IMETHODIMP Run()
> > >      {
> > >        MOZ_ASSERT(NS_IsMainThread());
> > > +      mRecorder->mReadThread->Shutdown();
> > > +      mRecorder->mReadThread = nullptr;
> > 
> > If we get a Start(), Stop(), Start() sequence, then this could shut down
> > mReadThread while it's being used by a different encoder.
> > 
> > I don't think we can really fix this bug without doing the
> > MediaRecorderSession idea.
> > 
> No, this won't fix the Start(), Stop(), Start() issue, it is for the case
> where someone calls Start() in the onstop() callback, this at least ensure
> the mReadThread is shut down. I've file a bug for MediaRecorderSession (bug
> 909640).
> 
bug 909670.

> > ::: content/media/encoder/TrackEncoder.cpp
> > @@ +89,5 @@
> > > +      Init(DEFAULT_CHANNELS, DEFAULT_SAMPLING_RATE);
> > > +      mRawSegment->AppendNullData(mSilentDuration);
> > > +      mSilentDuration = 0;
> > > +    } else {
> > > +      NotifyCancel();
> > 
> > I don't think we should do this. I think we should produce a zero-length
> > output.
> Changed in the new patch.

Comment 25

[Shelly Lin [:shelly]]

Attachment: Mochitest test case

I've added the check of zero blob size back due to the fix per Rob's request. The expected result should be an audio file with headers and zero duration.

Also, I've removed the check of single call of ondataavailable, I think it's okay to receive multiple calls of ondataavailable (although it won't do that here). Or would you prefer adding the check back?

Comment 26

[Jason Smith [:jsmith]]

Comment on attachment 797085 [details] [diff] [review]
Mochitest test case

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

Some questions inline. I'm confused here if the blob size check should be = 0 or greater than zero. Can you explain?

Also - small nit to fix the commit message when you get the chance to have user = you and r= after the period with the reviewer IRC nick included.

Kicking off a try run here would be a good idea as well.

::: content/media/test/test_mediarecorder_record_immediate_stop.html
@@ +57,5 @@
> +
> +  // This handler verifies that ondataavailable events handler are fired with
> +  // the blob generated having greater than zero size and a correct mime type.
> +  mediaRecorder.ondataavailable = function (evt) {
> +    onDataAvailableFired = true;

Can you explain more why it would be okay to get more than ondataavailable event in this case?

@@ +63,5 @@
> +    ok(evt instanceof BlobEvent,
> +       'Events fired from ondataavailable should be BlobEvent');
> +    is(evt.type, 'dataavailable',
> +       'Event type should dataavailable');
> +    ok(evt.data.size > 0,

This indicates greater than zero, but an earlier comment indicates this should be equal to zero. Can you clarify?

Comment 27

[Shelly Lin [:shelly]]

(In reply to Jason Smith [:jsmith] from comment #26)
> Comment on attachment 797085 [details] [diff] [review]
> Mochitest test case
> 
> Review of attachment 797085 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Some questions inline. I'm confused here if the blob size check should be =
> 0 or greater than zero. Can you explain?
The size of blob is greater than zero because it contains ogg headers and an ogg page, but the duration of this audio is zero length.

> 
> Also - small nit to fix the commit message when you get the chance to have
> user = you and r= after the period with the reviewer IRC nick included.
I was thinking merging this test patch into the fix patch later, but will change it next.

> 
> Kicking off a try run here would be a good idea as well.
> 
Can you explain more about the try run?

> ::: content/media/test/test_mediarecorder_record_immediate_stop.html
> @@ +57,5 @@
> > +
> > +  // This handler verifies that ondataavailable events handler are fired with
> > +  // the blob generated having greater than zero size and a correct mime type.
> > +  mediaRecorder.ondataavailable = function (evt) {
> > +    onDataAvailableFired = true;
> 
> Can you explain more why it would be okay to get more than ondataavailable
> event in this case?

It won't because the recorder is started with no time slice here. I'll put that logic back.

> 
> @@ +63,5 @@
> > +    ok(evt instanceof BlobEvent,
> > +       'Events fired from ondataavailable should be BlobEvent');
> > +    is(evt.type, 'dataavailable',
> > +       'Event type should dataavailable');
> > +    ok(evt.data.size > 0,
> 
> This indicates greater than zero, but an earlier comment indicates this
> should be equal to zero. Can you clarify?

Which comment are you referring to? My original fix is producing zero size blob but Rob suggested we should produce zero-length output, which its duration would be zero but the result file size would be greater than zero, as I explained above.

Comment 28

[Shelly Lin [:shelly]]

Attachment: Mochitest test case

Please find my comments in comment 27, thanks :)

Comment 29

[Shelly Lin [:shelly]]

Attachment: Handle the immediate Stop after a Start call of MediaRecorder

Update the patch comment.

Comment 30

[Jason Smith [:jsmith]]

What I mean to say about the try run is that you should kick off a try run using the attached fix here and the mochitest to verify that this works as expected when ran in CI across machines.

Comment 31

[Shelly Lin [:shelly]]

(In reply to Jason Smith [:jsmith] from comment #30)
> What I mean to say about the try run is that you should kick off a try run
> using the attached fix here and the mochitest to verify that this works as
> expected when ran in CI across machines.

Ohoh, yeah of course. I did run the fix patch with this mochitest and it works as expected.

Try server result:
https://tbpl.mozilla.org/?tree=Try&rev=b78b01435683

Comment 32

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/b2g-inbound/rev/b3668dd7f955
https://hg.mozilla.org/integration/b2g-inbound/rev/af09edead9b8

Comment 33

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/b3668dd7f955
https://hg.mozilla.org/mozilla-central/rev/af09edead9b8

Comment 34

[Jason Smith [:jsmith]]

Verified via mochitest landing.