New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 710845 link

Starred by 2 users

Issue metadata

Status: Verified
Owner:
Closed: Apr 2017
Cc:
EstimatedDays: ----
NextAction: ----
OS: Linux
Pri: 1
Type: Bug



Sign in to add a comment

CHECK failure: buffer->timestamp() >= base::TimeDelta() (-NUMBER s vs. 0 s) in ffmpeg_demuxer.c

Project Member Reported by ClusterFuzz, Apr 12 2017

Issue description

Detailed report: https://clusterfuzz.com/testcase?key=5589284443914240

Fuzzer: libfuzzer_media_pipeline_integration_fuzzer
Job Type: libfuzzer_chrome_asan_debug
Platform Id: linux

Crash Type: CHECK failure
Crash Address: 
Crash State:
  buffer->timestamp() >= base::TimeDelta() (-NUMBER s vs. 0 s) in ffmpeg_demuxer.c
  media::FFmpegDemuxerStream::EnqueuePacket
  media::FFmpegDemuxer::OnReadFrameDone
  
Sanitizer: address (ASAN)

Regressed: https://clusterfuzz.com/revisions?job=libfuzzer_chrome_asan_debug&range=444427:444575

Reproducer Testcase: https://clusterfuzz.com/download/AMIfv97SAeTLhar_riIL5BNozcbrBYDyI9twcvjEHlegt8ONM2uL2o1QxiYHv956SaDZ-rwSwlvG6oiZRo6d2joKO6XUK_ttqovzq_MQc2vt66u8UrFkT3RdMxSAzA8G5veBFfRFOtIF1UpV18AG4ZszhBgTYm1Dj00_ZJ_J7TS46esdn0ZOO_r17FmX3wAWYcMocappbNMRbbU8KPUQaLWSW1AFoYH2VmMopqslVP2aU53whHdYdUc44tPHKvavvkLpKjVA1mUAXm77yPmU5oYDDPffN34qhSjN7iGraRjPSHggtVzZIDvcowLMU5kOFtz2iR3yAv9C30W4AKLI_WdDsbDLQVFlE1wxPcoGMQGZ-NH1ZsVl-Zc?testcase_id=5589284443914240


Issue filed automatically.

See https://chromium.googlesource.com/chromium/src/+/master/testing/libfuzzer/reproducing.md for more information.
 
Cc: msrchandra@chromium.org
Labels: Test-Predator-Wrong-CLs M-58
Owner: sande...@chromium.org
Status: Assigned (was: Untriaged)
Predator and CL did not provide any possible suspects.
Using Code Search for the file, "ffmpeg_demuxer.c" assigning to the concern owner.
Suspecting Commit#
https://chromium.googlesource.com/chromium/src/+/b20148e73c9d380f84968dac00dae26425d05b78

@sandersd -- Could you please look into the issue, kindly re-assign if this is not related to your changes.
Thank You.
Project Member

Comment 2 by bugdroid1@chromium.org, Apr 19 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7ef29df1ba9940551cbe64afd833706799bf6034

commit 7ef29df1ba9940551cbe64afd833706799bf6034
Author: sandersd <sandersd@chromium.org>
Date: Wed Apr 19 18:31:20 2017

Media: Reject negative initial timestamps in FFmpegDemuxer.

During recent changes, it became possible for the first video buffer
timestamp in a stream to be negative. This change restores the invariant
that video buffer timestampes are non-negative, by emitting a demuxer
error in this case.

BUG= 710845 

Review-Url: https://codereview.chromium.org/2822063002
Cr-Commit-Position: refs/heads/master@{#465678}

[modify] https://crrev.com/7ef29df1ba9940551cbe64afd833706799bf6034/media/filters/ffmpeg_demuxer.cc

Project Member

Comment 3 by ClusterFuzz, Apr 20 2017

ClusterFuzz has detected this issue as fixed in range 465662:465713.

Detailed report: https://clusterfuzz.com/testcase?key=5589284443914240

Fuzzer: libfuzzer_media_pipeline_integration_fuzzer
Job Type: libfuzzer_chrome_asan_debug
Platform Id: linux

Crash Type: CHECK failure
Crash Address: 
Crash State:
  buffer->timestamp() >= base::TimeDelta() (-NUMBER s vs. 0 s) in ffmpeg_demuxer.c
  media::FFmpegDemuxerStream::EnqueuePacket
  media::FFmpegDemuxer::OnReadFrameDone
  
Sanitizer: address (ASAN)

Regressed: https://clusterfuzz.com/revisions?job=libfuzzer_chrome_asan_debug&range=444427:444575
Fixed: https://clusterfuzz.com/revisions?job=libfuzzer_chrome_asan_debug&range=465662:465713

Reproducer Testcase: https://clusterfuzz.com/download/AMIfv97SAeTLhar_riIL5BNozcbrBYDyI9twcvjEHlegt8ONM2uL2o1QxiYHv956SaDZ-rwSwlvG6oiZRo6d2joKO6XUK_ttqovzq_MQc2vt66u8UrFkT3RdMxSAzA8G5veBFfRFOtIF1UpV18AG4ZszhBgTYm1Dj00_ZJ_J7TS46esdn0ZOO_r17FmX3wAWYcMocappbNMRbbU8KPUQaLWSW1AFoYH2VmMopqslVP2aU53whHdYdUc44tPHKvavvkLpKjVA1mUAXm77yPmU5oYDDPffN34qhSjN7iGraRjPSHggtVzZIDvcowLMU5kOFtz2iR3yAv9C30W4AKLI_WdDsbDLQVFlE1wxPcoGMQGZ-NH1ZsVl-Zc?testcase_id=5589284443914240


See https://chromium.googlesource.com/chromium/src/+/master/testing/libfuzzer/reproducing.md for more information.

If you suspect that the result above is incorrect, try re-doing that job on the test case report page.
Project Member

Comment 4 by ClusterFuzz, Apr 20 2017

Labels: ClusterFuzz-Verified
Status: Verified (was: Assigned)
ClusterFuzz testcase 5589284443914240 is verified as fixed, so closing issue.

If this is incorrect, please add ClusterFuzz-Wrong label and re-open the issue.
Hi sandersd,
Can you give a bit more context on what exactly broke without this fix?
It seems starting with v58 I'm unable to play back a bunch of videos.
chrome://media-internals says it's failing because of this negative timestamp issue - but they used to play back fine before 58 :(
I've also seen several crbug's filed that seemed to reference the same issue.

Do you know if there are any plans to e.g. enable users to override the default for enable_negative_timestamp_fixups via command line flag? (Or even better change the default to true, but I assume that breaks something?)
When a timestamp is negative, there are only two possible interpretations:
  - There is a bug in the demuxer.
  - The media is muxed incorrectly.

The reason for this is that we expect the demuxer to emit a 'track start time' and everything should be (non-negative) relative to that. This is an invariant that we intend to keep, unless we start to see a much higher rate of failure caused by it.

We did have a few releases plagued by incorrect edit list computation in the demuxer. I would predict that the issues you are seeing have been fixed already.

Here is what I recommend:
  - Test with Chrome Canary.
  - If you still have a problem, and are able to do so, send us a copy of the broken media. (I can provide a private means to do so if the bug tracker isn't appropriate.)
Thanks!
I'm on Linux, so the latest channel I can get on is Dev, where it is still broken :(
And yes, I believe it's a video issue (the first two frames seem to have tiny negative offsets), so the proper way would be to fix the camera firmware that's producing them, but not sure how feasible that is :(
Do you think the fix could be in Canary but not Dev (so should I wait?)
And if not, does it still make sense to send you a sample video or is that the case you described which is unlikely to get fixed?

Thanks! :)
I think Dev is pretty close to Canary right now in terms of edit list processing. We have one major change to edit lists still pending, but I expect we will flip that right after M63 is branched (Thursday) to give us the maximum amount of time for testing.

I think that in every case here we would benefit from additional media to test with!
Awesome, thanks! :)
Unfortunately the only video from one of those cams I have access to right now is one recorded by someone else, so I'd rather not share that one.
However, I can get my hands on a bunch of cameras tomorrow morning that all seem to record videos in this broken(?) state, so I'll make sure to capture and upload one first thing in the morning! :)

Thanks again for looking into this and for your help!
Alright, recorded one with a negative timestamp! :)
It was unfortunately too large to attach, so I uploaded it via Dropbox:
https://www.dropbox.com/s/rbbm043bo4j4e6h/negative_timestamp.mp4?dl=0
(Feel free to rehost somewhere else if that's more convenient for you)
The specific problem with this file is that the edit list is incorrect. I can't easily measure what the correct A/V sync is, but modifying the edit list does work around the issue. Precise details:

  - The edit offset is an i32 at 0x294.
  - The value in the file is 64064 (0x0000FA40), which is the PTS (in 1/480000ths of a second units) of the first frame in decode order.
  - The first frame is a SAP type 2; the first frame in presentation order is actually the second frame in decode order.
  - The second frame has PTS 16016 (0x00003E90).
  - Overwriting the value with 16016 (or removing the edit list entirely) works around the issue.

Unfortunately this means that the media really is incorrect. However, there is some chance that our upcoming changes in M64 will result in marking some of these frames as discard frames, which will restore playback. That said, I expect your audio sync will be off by about 133ms.

The actual encoded video is fine, the problem is somewhere in the muxing process. You may be able to find a different muxing process or a simple post-processing step that solves the issue as well.
Awesome, thanks for the detailed analysis sandersd! :D
FYI, your test recording now plays in Chrome Canary, and the changes to support that will be shipped in M64.
Awesome, thanks for letting me know! :)

Sign in to add a comment