MediaFormatReader returns wrong sample after seeking.

RESOLVED FIXED in Firefox 49

Status

()

P2
normal
RESOLVED FIXED
3 years ago
2 years ago

People

(Reporter: kaku, Assigned: kaku)

Tracking

unspecified
mozilla49
All
Windows
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox49 fixed)

Details

User Story

This is a sub-bug of bug 1193124.
So, the described issue in comment 1 is only observable by first applying the patch of bug 1193124.

Attachments

(3 attachments)

(Assignee)

Description

3 years ago
Created attachment 8751665 [details]
test.html

Following bug 1193124 comment 11.

The attachment is a simplified test case which load small-shot.mp3, play it to the end and then set its currentTime to 0. After receiving the 'seeked' event, the audio's currentTime should be 0 but 0.026612.

BTW, this bug cannot be re-produced at the released Firefox46 but could be re-produced at the mozilla-central. So, it might be a regression.
(Assignee)

Comment 1

3 years ago
Created attachment 8751667 [details]
small-shot.mp3
(Assignee)

Updated

3 years ago
Blocks: 1193124
there is nothing we can do about this in MediaFormatReader as this depends on the decoder itself and what API they provide.

The mac decoder for example, will always drop the first MP3 frame. But as the decoding API provides no way to tell which frame is returned, we use the pts of the 2nd input frame (usually 0.026612).
It's the same with the DirectShow reader on Windows XP.

So while you seek at 0, and the first frame passed to the decoder is 0, the first frame coming out of the decoder will have the pts of the second input frame. 

It was working in 46 because it was buggy, and this is what caused some intermittent failures on mochitest.

The WMF will work properly and will have the first frame tag as 0.

AAC doesn't cause this problem with the Apple decoder, only mp3.

BTW, it would be the same with opus. When you seek to 0, the first 30ms are dropped, so the first frame returned will always have a time of 30ms at least.

So the behaviour is platform dependent, and we can never be certain in advance of what the MediaDataDecoder will do (not all MP3 frames see their first sample being dropped). I believe the frames dropped are those containing a VBR header.
Status: NEW → UNCONFIRMED
Ever confirmed: false
oh, and forgot to add:

The MediaFormatReader time is not always starting at 0.
It is up to the MediaDecoderReaderWrapper to adjust the start time.

So it's normal to see the first frame coming out of the MediaFormatReader to not be 0, but some time in the future.

Could it be that following the changes to the MediaDecoderReaderWrapper , the start time is no longer adjusted?

Before bug 1244639, the mp3 demuxer data wasn't shifted to start at 0 in order to get around the mac decoder issue, but this has been fixed.

JW, could it be due to something not working in MediaDecoderReaderWrapper?
Status: UNCONFIRMED → NEW
Ever confirmed: true
Flags: needinfo?(jwwang)
It could also be an issue in the MP3Demxuer where seeking to 0 doesn't always return the first frame.

Seeking is rather an approximate affair with mp3
Flags: needinfo?(esawin)
(Assignee)

Comment 5

3 years ago
(In reply to Jean-Yves Avenard [:jya] from comment #3)
> oh, and forgot to add:
> 
> The MediaFormatReader time is not always starting at 0.
> It is up to the MediaDecoderReaderWrapper to adjust the start time.
> 
> So it's normal to see the first frame coming out of the MediaFormatReader to
> not be 0, but some time in the future.
> 
> Could it be that following the changes to the MediaDecoderReaderWrapper ,
> the start time is no longer adjusted?
> 
> Before bug 1244639, the mp3 demuxer data wasn't shifted to start at 0 in
> order to get around the mac decoder issue, but this has been fixed.
> 
> JW, could it be due to something not working in MediaDecoderReaderWrapper?

No, it is not. 
In the test case, the audio is first played to the end and the logs show that the MFR emits the following sample sequences:
1st:[26122, 52244], 2nd:[52244, 78366], 3rd:[78366, 104489],...... (<-- before adjusting start time)

And the MDSM receives the following sample sequences:
1st:[0, 26122]      2nd:[26122, 52244], 3rd:[52244, 78366],...... (<-- time has adjusted by the Wrapper)

The MediaDecoderReaderWrapper knows that the start time is 26122 and works well.

I think it is somewhat weird that the 1st sample [26122, 52244] was ever returned by the MFR but cannot be seeked/requested again later...
(In reply to Jean-Yves Avenard [:jya] from comment #4)
> It could also be an issue in the MP3Demxuer where seeking to 0 doesn't
> always return the first frame.
> 
> Seeking is rather an approximate affair with mp3

Seeking to 0 is short-circuited to setting mFrameIndex=0 and mOffset=mFirstFrameOffset. This is the same path used as during Init(). So we shouldn't see any difference between initial playback and seeking to 0.

I can't reproduce the issue on Fennec or the latest Windows Nightly, currentTime shows correctly as 0 after seeking.
Flags: needinfo?(esawin)
What are the timestamps (unadjusted) of first decoded frames after seeking if you call MediaDecoderReader::Seek(0), MediaDecoderReader::Seek(26122), and MediaDecoderReader::Seek(26121) respectively?
Flags: needinfo?(jwwang) → needinfo?(kaku)
(Assignee)

Comment 8

3 years ago
Oh! Sorry, it's my fault. The wrong currentTime is only observable by first applying the patch of bug 1193124.  If you do not apply, the "wrong seeked time" is still there but not updated to the HTMLMediaElement.

esawin, could you please have another look on this?
Flags: needinfo?(esawin)
(Assignee)

Updated

3 years ago
User Story: (updated)
(Assignee)

Comment 9

3 years ago
(In reply to JW Wang [:jwwang] from comment #7)
> What are the timestamps (unadjusted) of first decoded frames after seeking
> if you call MediaDecoderReader::Seek(0), MediaDecoderReader::Seek(26122),
> and MediaDecoderReader::Seek(26121) respectively?

First of all, we are not able to call MediaDecoderReader::Seek(0) because the media start time is 26122, so the earlest position we can seek to is 26122. Or, you are talking about MediaDecoderReaderWRAPPER::Seek(0) then here is the numbers:

MediaDecoderReaderWrapper::Seek(0)     -> MediaDecoderReader::Seek(26122) -> 1st decoded frame: 52244
MediaDecoderReaderWrapper::Seek(26122) -> MediaDecoderReader::Seek(52244) -> 1st decoded frame: 78366
MediaDecoderReaderWrapper::Seek(26121) -> MediaDecoderReader::Seek(52243) -> 1st decoded frame: 78366
Flags: needinfo?(kaku)
No, I mean to hack the code to see what results are returns for different seek target.
Ok. So the issue I mentioned are what I wrote in my first post. 

The first audio frame returned *is* 0. It just happens that some decoder will drop it and only return the 2nd. 

So the start time is set to the time of the 2nd frame. Now when seeking to 0; you end up seeking at the time of the 2nd frame instead and as the decoder drops the first frame input, it returns here the 3rd audio frame. 

Conclusion, when seeking to 0; always pass the value 0 to the MediaFormatReader regardless of start time.
Though, I remember a bug not long ago due to seeking not adjusting the time. So I don't know the best work around.
what happens if you seek to 0.000001s or 0.000002s? Will the decoder return 52244us?
(Assignee)

Comment 14

3 years ago
(In reply to JW Wang [:jwwang] from comment #10)
> No, I mean to hack the code to see what results are returns for different
> seek target.
Okay, here you are:
MediaDecoderReader::Seek(0)     -> 1st decoded frame: 26122
MediaDecoderReader::Seek(26121) -> 1st decoded frame: 26122
MediaDecoderReader::Seek(26122) -> 1st decoded frame: 52244

I think you are right that the audio sample which starts from 26122 is still there but somehow cannot be requested agian.
The first frame contains the seek target. So the demuxer returns the first frame but the decoder returns only the 2nd. 

Then you seek to the 2nd frame and the decoder returns the 3rd. 

the issue really here is that the demuxer think it's working with a start time of 0 but the decoder doesn't.
So this is a bug in the decoder?
Maybe we should add a mechanism where the MFR records the time of the first frame demuxed and the time of the first frame decided. 

It can then only use the time of the first frame demuxed instead of the time of the first frame decoded. 

Seeking is mostly a demuxer job anyway.
(In reply to JW Wang [:jwwang] from comment #16)
> So this is a bug in the decoder?

It's just the way the decoder works.
It is curious the test fails on Windows only. Does windows decoder behave differently?
(In reply to JW Wang [:jwwang] from comment #19)
> It is curious the test fails on Windows only. Does windows decoder behave
> differently?

Windows decoder behave slightly differently than the Mac or ffmpeg one.

Mac set the decoded sample time to the time of the last input sample. This is why the first sample decoded has the time of the 2nd sample demuxed. 
Ffmpeg actually sets the time of the decoded sample to the time of the sample that was used to produce the decode.

Windows on the other hand, set the time of the first decoded sample to 0 and then use a counter with how many samples have been decoded so far and use this to calculate the time of each sample coming out.

I don't know about gonk or android audio decoder.

Updated

3 years ago
Flags: needinfo?(esawin)
(Assignee)

Comment 21

3 years ago
Created attachment 8752754 [details]
MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r=jya

Review commit: https://reviewboard.mozilla.org/r/52774/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/52774/
Attachment #8752754 - Flags: review?(jyavenard)
Have more fun in seek!
Assignee: nobody → kaku
Status: NEW → ASSIGNED
Priority: -- → P2
(Assignee)

Comment 23

3 years ago
Comment on attachment 8752754 [details]
MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r=jya

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52774/diff/1-2/
(Assignee)

Updated

3 years ago
Attachment #8752754 - Attachment is obsolete: true
Attachment #8752754 - Flags: review?(jyavenard)
(Assignee)

Comment 25

3 years ago
Comment on attachment 8752754 [details]
MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r=jya

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52774/diff/2-3/
Attachment #8752754 - Attachment is obsolete: false
Attachment #8752754 - Flags: review?(jyavenard)
Comment on attachment 8752754 [details]
MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r=jya

https://reviewboard.mozilla.org/r/52774/#review50212

::: dom/media/MediaFormatReader.h:407
(Diff revision 3)
>      Maybe<media::TimeUnit> mLastTimeRangesEnd;
>      RefPtr<SharedTrackInfo> mInfo;
> +
> +    Maybe<media::TimeUnit> mFirstDemuxedSampleTime;
> +
> +    void SetFirstDemuxedSampleTime() {

I'd prefer if you made this function take the time as argument.

It doesn't need to know about mQueuedSamples.

Use mFirstDemuxedSampleTime = Some(...)

Perform all the logic inside MediaFormatReader::HandleDemuxedSamples

::: dom/media/MediaFormatReader.h:521
(Diff revision 3)
>    // Set the demuxed-only flag.
>    Atomic<bool> mDemuxOnly;
>  
>    // Seeking objects.
> +  void SetSeekTarget(SeekTarget&& aTarget);
> +  media::TimeUnit GetMinFristDemuxedTime();

s/Frist/First

But DemuxStartTime() seems more appropriate to me, so it's similar to the StartTime() function

::: dom/media/MediaFormatReader.cpp:926
(Diff revision 3)
>  
>    if (!EnsureDecoderInitialized(aTrack)) {
>      return;
>    }
>  
> +  if (!ForceZeroStartTime()) {

Please move the logic here,

so if (!ForceZeroStartTime && decoder.mFirstDemuxedSampleTime.isNothing) { .... }

::: dom/media/MediaFormatReader.cpp:1535
(Diff revision 3)
> +  mOriginalSeekTarget = Some(aTarget);
> +  mPendingSeekTime = Some(aTarget.GetTime());
> +}
> +
> +TimeUnit
> +MediaFormatReader::GetMinFristDemuxedTime()

The coding style expressly say that a function name GetXXXX() means that it can fail.

This function can never fail. So it shouldn't be called GetMinFirstDemuxedTime.

As mentioned earlier, please use DemuxStartTime()

::: dom/media/MediaFormatReader.cpp:1542
(Diff revision 3)
> +  MOZ_ASSERT(OnTaskQueue());
> +
> +  TimeUnit minTime = TimeUnit::FromMicroseconds(INT64_MAX);
> +
> +  if (HasAudio()) {
> +    auto& audioDecoder = GetDecoderData(TrackType::kAudioTrack);

Just use mAudio here, no need to call GetDecoderData

::: dom/media/MediaFormatReader.cpp:1544
(Diff revision 3)
> +  TimeUnit minTime = TimeUnit::FromMicroseconds(INT64_MAX);
> +
> +  if (HasAudio()) {
> +    auto& audioDecoder = GetDecoderData(TrackType::kAudioTrack);
> +    MOZ_ASSERT(audioDecoder.mFirstDemuxedSampleTime.isSome());
> +    if (audioDecoder.mFirstDemuxedSampleTime.ref() < minTime) {

You should remove all the logic testing that mFirstDemuxedSampleTime is set.

You can assert that (!HasAudio() || mAudio.mFirstDemuxedSampleTime.isSome()) && (!HasVideo() || mVideo.mFirstDemuxedSampleTime.isSome())

It would be an error for MDSM to call seek prior first frame decoding having started..

Please also assert that it's not called if ForceZeroStartTime is true.

::: dom/media/MediaFormatReader.cpp:1553
(Diff revision 3)
> +
> +  if (HasVideo()) {
> +    auto& videoDecoder = GetDecoderData(TrackType::kVideoTrack);
> +    MOZ_ASSERT(videoDecoder.mFirstDemuxedSampleTime.isSome());
> +    if (videoDecoder.mFirstDemuxedSampleTime.ref() < minTime) {
> +      minTime = videoDecoder.mFirstDemuxedSampleTime.ref();

please use std::min.

std::min(HasAudio() ? mAudio.mFirstDemuxedSampleTime.ref() : TimeUnit::FromInfinity(), HasVideo() ? mVideo.mFirstDemuxedSampleTime.ref() : TimeUnit::FromInfinity()) will replace everything you have here with a single line

::: dom/media/MediaFormatReader.cpp:1558
(Diff revision 3)
> +      minTime = videoDecoder.mFirstDemuxedSampleTime.ref();
> +    }
> +  }
> +
> +  // Should at least has audio or video.
> +  MOZ_ASSERT(minTime != TimeUnit::FromMicroseconds(INT64_MAX));

You can remove this if you have the assert at the start
Attachment #8752754 - Flags: review?(jyavenard)
(Assignee)

Comment 27

3 years ago
https://reviewboard.mozilla.org/r/52774/#review50212

> I'd prefer if you made this function take the time as argument.
> 
> It doesn't need to know about mQueuedSamples.
> 
> Use mFirstDemuxedSampleTime = Some(...)
> 
> Perform all the logic inside MediaFormatReader::HandleDemuxedSamples

If we don't hind the setting logics in this function, then I think we can just set the mFirstDemuxedSampleTime in the MediaFormatReader::HandleDemuxedSamples(); we don't need this function anymore.

> Please move the logic here,
> 
> so if (!ForceZeroStartTime && decoder.mFirstDemuxedSampleTime.isNothing) { .... }

So, we set the mFirstDemuxedSampleTime here without using a setter function.

> The coding style expressly say that a function name GetXXXX() means that it can fail.
> 
> This function can never fail. So it shouldn't be called GetMinFirstDemuxedTime.
> 
> As mentioned earlier, please use DemuxStartTime()

Got it, thanks.

> You should remove all the logic testing that mFirstDemuxedSampleTime is set.
> 
> You can assert that (!HasAudio() || mAudio.mFirstDemuxedSampleTime.isSome()) && (!HasVideo() || mVideo.mFirstDemuxedSampleTime.isSome())
> 
> It would be an error for MDSM to call seek prior first frame decoding having started..
> 
> Please also assert that it's not called if ForceZeroStartTime is true.

MDSM pass seek operation into reader only if the first sample has been decoded. The check is here: https://dxr.mozilla.org/mozilla-central/source/dom/media/MediaDecoderStateMachine.cpp#1464

And, yes, I should make sure that this is not called if the ForceZeroStartTime() is true.
(Assignee)

Comment 28

3 years ago
Comment on attachment 8752754 [details]
MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r=jya

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52774/diff/3-4/
Attachment #8752754 - Flags: review?(jyavenard)
Attachment #8752754 - Flags: review?(jyavenard) → review+
Comment on attachment 8752754 [details]
MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r=jya

https://reviewboard.mozilla.org/r/52774/#review50230

::: dom/media/MediaFormatReader.cpp:1519
(Diff revision 4)
>  
>    if (mShutdown) {
>      return SeekPromise::CreateAndReject(NS_ERROR_FAILURE, __func__);
>    }
>  
> -  mOriginalSeekTarget = aTarget;
> +  SetSeekTarget(Move(aTarget));

Don't bother with rvalue here and move semantic. it doesn't serve any purpose nor does it help clarity.

::: dom/media/MediaFormatReader.cpp:1529
(Diff revision 4)
>  
>    return p;
>  }
>  
>  void
> +MediaFormatReader::SetSeekTarget(SeekTarget&& aTarget)

take const SeekTarget& as parameter please

::: dom/media/MediaFormatReader.cpp:1536
(Diff revision 4)
> +  MOZ_ASSERT(OnTaskQueue());
> +
> +  // Transform the seek target time to the demuxer timeline.
> +  if (!ForceZeroStartTime()) {
> +    aTarget.SetTime(aTarget.GetTime() - TimeUnit::FromMicroseconds(StartTime())
> +                    + DemuxeStartTime());

Either DemuxerStartTime() or DemuxStartTime()

::: dom/media/MediaFormatReader.cpp:1551
(Diff revision 4)
> +  MOZ_ASSERT(OnTaskQueue());
> +  MOZ_ASSERT(!ForceZeroStartTime());
> +  MOZ_ASSERT((!HasAudio() || mAudio.mFirstDemuxedSampleTime.isSome()) &&
> +             (!HasVideo() || mVideo.mFirstDemuxedSampleTime.isSome()));
> +
> +  return std::min(HasAudio() ? mAudio.mFirstDemuxedSampleTime.ref() :

the coding style states that it should be:
test
? a
: b

with ? underneath the test and aligned.

https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Coding_Style#Operators
(Assignee)

Comment 30

3 years ago
Comment on attachment 8752754 [details]
MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r=jya

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52774/diff/4-5/
Attachment #8752754 - Attachment description: MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r?jya → MozReview Request: Bug 1272267 - adjust the seek target in the MediaFormatReader; r=jya
(Assignee)

Comment 32

3 years ago
Try looks good. Thanks for the review!
Keywords: checkin-needed

Comment 34

3 years ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/fb8ee867138d
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
status-firefox49: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla49
Depends on: 1290371
You need to log in before you can comment on or make changes to this bug.