Closed Bug 1219134 Opened 5 years ago Closed 5 years ago

FFmpeg decoder return wrong timestamps when draining.

Categories

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

defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla45
Tracking Status
firefox43 + fixed
firefox44 + fixed
firefox45 + fixed
b2g-v2.5 --- fixed

People

(Reporter: jwwang, Assigned: jya)

References

Details

Attachments

(8 files, 4 obsolete files)

1.41 KB, patch
eflores
: review+
Details | Diff | Splinter Review
4.80 KB, patch
eflores
: review+
Details | Diff | Splinter Review
7.00 KB, patch
jya
: review+
Details | Diff | Splinter Review
2.15 KB, patch
eflores
: review+
Details | Diff | Splinter Review
2.17 KB, patch
jya
: review+
Details | Diff | Splinter Review
6.28 KB, patch
jya
: review+
Details | Diff | Splinter Review
1.41 KB, patch
jya
: review+
Details | Diff | Splinter Review
4.78 KB, patch
eflores
: review+
Details | Diff | Splinter Review
run the command: NSPR_LOG_MODULES=timestamp:1,MediaDecoder:4,MediaSample:4 ./mach mochitest dom/media/test/seek.webm

logs:
Decoder=7f2ff0f67d40 OnVideoDecoded [3700000,3734000] disc=0
Decoder=7f2ff0f67d40 OnVideoDecoded [3733000,3767000] disc=0
Decoder=7f2ff0f67d40 OnVideoDecoded [3767000,3767000] disc=0
Decoder=7f2ff0f67d40 OnVideoDecoded [3800000,3800000] disc=0
Decoder=7f2ff0f67d40 OnVideoDecoded [3833000,3833000] disc=0
Decoder=7f2ff0f67d40 OnVideoDecoded [3867000,3867000] disc=0
Decoder=7f2ff0f67d40 OnVideoDecoded [3900000,3900000] disc=0
Decoder=7f2ff0f67d40 OnVideoDecoded [3933000,3933000] disc=0
Decoder=7f2ff0f67d40 OnVideoDecoded [3967000,3967000] disc=0

The duration of last few samples is zero.
logs with media.format-reader.webm=false:
Decoder=7f1e45b5c480 OnVideoDecoded [3700000,3733000] disc=0
Decoder=7f1e45b5c480 OnVideoDecoded [3733000,3767000] disc=0
Decoder=7f1e45b5c480 OnVideoDecoded [3767000,3800000] disc=0
Decoder=7f1e45b5c480 OnVideoDecoded [3800000,3833000] disc=0
Decoder=7f1e45b5c480 OnVideoDecoded [3833000,3867000] disc=0
Decoder=7f1e45b5c480 OnVideoDecoded [3867000,3900000] disc=0
Decoder=7f1e45b5c480 OnVideoDecoded [3900000,3933000] disc=0
Decoder=7f1e45b5c480 OnVideoDecoded [3933000,3967000] disc=0
Decoder=7f1e45b5c480 OnVideoDecoded [3967000,4001000] disc=0

No samples have zero duration.
Flags: needinfo?(jyavenard)
Assignee: nobody → jyavenard
Flags: needinfo?(jyavenard)
OS: Linux → All
Hardware: x86_64 → All
wonder if that could explain some of the stalls people have reported with MSE with high CPU usage (which would indicate that the TrackBuffersManager has issue with sample with 0 duration)
my guess is that those are the last frames ; we don't have an end timestamp so it uses the previous one.
Summary: MediaFormatReader gives wrong timestamps for seek.webm → FFmpeg VP8 decoder return wrong timestamps.
ok.. it's not the demuxer.. pfffff
The timestamps are correct with the media.format-reader.webm=false. Did the old reader make up them when there is no end timestamp?
WebMReader never use FFmpeg ; only libvpx.

You're on linux and you have FFmpeg which supports VP8 decoding, so this is what's used. Try setting edia.ffmpeg.enabled=false.

The timestamps provided to FFmpeg are good ; it's the sample coming out of the decoder that's not.

I already had to put a workaround for libav that caused all pts to be null and only the dts was properly set.

Looks like there's a problem for duration too (LibAV makes no use of the duration field, probably why the information is lost).
Ohh I see what's going on:

http://mxr.mozilla.org/mozilla-central/source/dom/media/platforms/ffmpeg/FFmpegH264Decoder.cpp#348

It's when draining the decoder; we feed the decoder null samples ; however the decoder output the frame duration of the new frame instead.

it's very wrong.
how did that ever worked :)
The logic was extracted from LibAV cmdutils.c. FFmpeg provides an API for that (av_frame_get_best_effort_timestamp()) unfortunately this isn't provided by LibAV.
So copy the logic instead in order to keep compatibility with the two forks.
Attachment #8679976 - Flags: review?(edwin)
We were incorrectly setting the keyframe flag of the last input sample rather than of the decoded one.
Attachment #8679977 - Flags: review?(edwin)
We default to the previous logic if for some unlikely condition we couldn't find the frame's duration (using the last input frame's duration)
Attachment #8679978 - Flags: review?(edwin)
The logic was extracted from LibAV cmdutils.c. FFmpeg provides an API for that (av_frame_get_best_effort_timestamp()) unfortunately this isn't provided by LibAV.
So copy the logic instead in order to keep compatibility with the two forks.
Attachment #8679979 - Flags: review?(edwin)
We were incorrectly setting the keyframe flag of the last input sample rather than of the decoded one.
Attachment #8679980 - Flags: review?(edwin)
We default to the previous logic if for some unlikely condition we couldn't find the frame's duration (using the last input frame's duration)

To drain the decoder, we feed empty data until no more frames come out of the decoder. However, the duration set on the decoded sample was the one of the last input: here that was 0.
As such as ffmpeg keeps 15 frames buffered at all time, when draining all last 15 frames would have had a duration incorrectly set to 0.
Attachment #8679983 - Flags: review?(edwin)
Comment on attachment 8679976 [details] [diff] [review]
P1. Use LibAV/FFmpeg logic to calculate pts.

bad git bz comment
Attachment #8679976 - Attachment is obsolete: true
Attachment #8679976 - Flags: review?(edwin)
Comment on attachment 8679977 [details] [diff] [review]
P2. Properly set the keyframe flag.

bad git bz comment
Attachment #8679977 - Attachment is obsolete: true
Attachment #8679977 - Flags: review?(edwin)
Comment on attachment 8679978 [details] [diff] [review]
P3. Properly assign the decoded sample duration.

bad git bz comment
Attachment #8679978 - Attachment is obsolete: true
Attachment #8679978 - Flags: review?(edwin)
Here is the code calculating the pts in FFmpeg:
http://www.ffmpeg.org/doxygen/2.0/libavcodec_2utils_8c_source.html#l01827

this is libav: https://git.libav.org/?p=libav.git;a=blob;f=cmdutils.c;hb=HEAD#l1436
Summary: FFmpeg VP8 decoder return wrong timestamps. → FFmpeg decoder return wrong timestamps when draining.
Comment on attachment 8679979 [details] [diff] [review]
P1. Use LibAV/FFmpeg logic to calculate pts.

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

::: dom/media/platforms/ffmpeg/FFmpegDataDecoder.cpp
@@ +38,5 @@
> +    mNum_faulty_dts += aDts <= mLast_dts;
> +    mLast_dts = aDts;
> +  }
> +  if (aPts != int64_t(AV_NOPTS_VALUE)) {
> +    mNum_faulty_pts += aPts <= mLast_pts;

grumble grumble r+
Attachment #8679979 - Flags: review?(edwin) → review+
The logic was extracted from LibAV cmdutils.c. FFmpeg provides an API for that (av_frame_get_best_effort_timestamp()) unfortunately this isn't provided by LibAV.
So copy the logic instead in order to keep compatibility with the two forks.

Removing the grumble grumble factor. clang also optmise this better, removing two instructions (albeit one extra jump)

Carrying r+
Attachment #8680463 - Flags: review+
Attachment #8679979 - Attachment is obsolete: true
This is the primary reason why we got no pts returned (pts were set to 0) when using early version of LibAV. Apparently you are expected to set the pts when allocating the buffer of a frame.
This is undocumented, but both LibAV and FFmpeg do so internally. So do the same.
Attachment #8681003 - Flags: review?(edwin)
This is the primary reason why we got no pts returned (pts were set to 0) when using early version of LibAV. Apparently you are expected to set the pts when allocating the buffer of a frame.
This is undocumented, but both LibAV and FFmpeg do so internally. So do the same.
Attachment #8681028 - Flags: review+
The logic was extracted from LibAV cmdutils.c. FFmpeg provides an API for that (av_frame_get_best_effort_timestamp()) unfortunately this isn't provided by LibAV.
So copy the logic instead in order to keep compatibility with the two forks.


Rebase, Carrying r+
Attachment #8681029 - Flags: review+
We were incorrectly setting the keyframe flag of the last input sample rather than of the decoded one.


Rebase, Carrying r+
Attachment #8681030 - Flags: review+
We default to the previous logic if for some unlikely condition we couldn't find the frame's duration (using the last input frame's duration)


Rebase, Carrying r+
Attachment #8681031 - Flags: review?(edwin)
I asked Tomcat to perform that backout as the video reported in bug 1220051 does weird thing with this and ffmpeg 2.4 (an older version I was testing with).

So to give me time to investigate further...
[Tracking Requested - why for this release]:

In bug 1213499 comment 7, Jean-Yves said this fix must be uplifted to 43 now that we have enabled H.264 on Linux. It will fix some video stalls.
Comment on attachment 8681028 [details] [diff] [review]
P1. Fix pts calculation in FFmpeg video decoder.

Request is for all 4 patches. Though can do without patch #2.
Approval Request Comment
[Feature/regressing bug #]:1219134
[User impact if declined]:video frames may be displayed out of order on some old version of libav. Last 16 frames of a video will never be displayed.
[Describe test coverage new/current, TreeHerder]: In central, local test
[Risks and why]: Low, this is performing some decoding as it was always meant to be.
[String/UUID change made/needed]: none.
Attachment #8681028 - Flags: approval-mozilla-beta?
Attachment #8681028 - Flags: approval-mozilla-aurora?
Reason for uplift request is that all existing changes to ffmpeg have already been uplifted to 43.

Me way want to only uplift to aurora (44) first and let it bake a week or so until moving to beta.
Jean-Yves, could you please nominate all patches that needs uplifting individually? In comment31 you mention 4 patches but I see almost 8 patches attached to the bug.
Flags: needinfo?(jyavenard)
Please use the 4 commits as pushed to central
Flags: needinfo?(jyavenard)
Comment on attachment 8681028 [details] [diff] [review]
P1. Fix pts calculation in FFmpeg video decoder.

OK, taking it as it improves the video situation for GNU/Linux user.
Should be in 43 beta 2.
Tomcat, please note that we have 4 patches. Not sure what to approve here. :)
Flags: needinfo?(cbook)
Attachment #8681028 - Flags: approval-mozilla-beta?
Attachment #8681028 - Flags: approval-mozilla-beta+
Attachment #8681028 - Flags: approval-mozilla-aurora?
Attachment #8681028 - Flags: approval-mozilla-aurora+
part 2 failed to apply to beta:

Tomcats-MacBook-Pro-2:mozilla-central Tomcat$ hg graft --edit -r edf316f6255f
grafting 313466:edf316f6255f "Bug 1219134 - P2. Use LibAV/FFmpeg logic to detect invalid pts. r=edwin, a=sylvestre"
merging dom/media/platforms/ffmpeg/FFmpegH264Decoder.cpp
merging dom/media/platforms/ffmpeg/FFmpegH264Decoder.h
warning: conflicts during merge.
merging dom/media/platforms/ffmpeg/FFmpegH264Decoder.h incomplete! (edit conflicts, then use 'hg resolve --mark')
abort: unresolved conflicts, can't continue
(use hg resolve and hg graft --continue)
Flags: needinfo?(cbook) → needinfo?(jyavenard)
Fixed already, belatedly tracking since this was a recent regression.
You need to log in before you can comment on or make changes to this bug.