New issue
Advanced search Search tips

Issue 667210 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Jan 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: All
Pri: 2
Type: Bug



Sign in to add a comment

video_VideoSeek failing on Intel boards

Project Member Reported by wuchengli@chromium.org, Nov 21 2016

Issue description

The failure reason is "Seek test is stuck and timeout".

https://wmatrix.googleplex.com/unfiltered?hide_missing=True&tests=video_VideoSeek&days_back=45&releases=56

daisy, peach, and elm are fine.
 
Components: OS>Kernel>Video
Labels: OS-Chrome
Status: Started (was: Assigned)
I took a look at Cyan failures. 

https://wmatrix.googleplex.com/platform/unfiltered?hide_missing=True&tests=video_VideoSeek&platforms=cyan&days_back=30

E.g.,

https://wmatrix.googleplex.com/testrun/unfiltered?test_ids=384351438
where, it got stuck in the 13rd seek.

Surprisingly, it is not about resolution change. In that last 3 failed cases,  all failed with a normal h264 video.

Will investigate deeper.

It's an h264 decoder error (a complete chrome log is attached):

[29693:30044:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(557)] End of input buffer 2782
[29693:29693:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(996)] Got reset request
[29693:30044:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(535)] New current bitstream buffer, id: 2783 size: 28
[29693:30044:1125/104714:ERROR:h264_decoder.cc(1301)] New input stream at: 0x7f0aafd99000 size: 28
[29693:30044:1125/104714:ERROR:h264_decoder.cc(1430)] Skipping NALU type: 0
[29693:30044:1125/104714:ERROR:h264_decoder.cc(1434)] NALU done
[29693:30044:1125/104714:ERROR:h264_decoder.cc(1322)] New NALU: 1
[29693:30044:1125/104714:ERROR:h264_decoder.cc(100)] Decoding POC 0
[29693:30044:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(1406)] Decoding POC 0
[29693:30044:1125/104714:ERROR:h264_decoder.cc(943)] Finishing picture frame_num: 0, entries in DPB: 0
[29693:30044:1125/104714:ERROR:h264_decoder.cc(1162)] Invalid frame_num: 2
[29693:30044:1125/104714:ERROR:h264_decoder.cc(1363)] Error during decode
[29693:30044:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(641)] Error decoding stream
[29693:30044:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(975)] ResetTask
[29693:29693:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(293)] Notifying of error 4
[29693:30044:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(557)] End of input buffer 2783
[29693:29693:1125/104714:ERROR:vaapi_video_decode_accelerator.cc(1072)] Destroying VAVDA


https://cs.chromium.org/chromium/src/media/gpu/h264_decoder.cc?q=h264_decoder.h&sq=package:chromium&dr=C&l=15
chrome
3.5 MB View Download
This looks like an invalid stream, it looks like we get SPS, PPS, and then an IDR (type 5), but the subsequent NALU type 1 has frame_num=2, which means we have a frame_num gap, which this stream disallows via gaps_in_frame_num_value_allowed_flag=false?
Looking at the log, in correct cases we get this sequence of bitstream buffers:

bitstream buffer size 805, containing NALUs: 7, 8, 6, 5 with frame_num=0
bitstream buffer size 23, NALUs: 1 with frame_num=1
bitstream buffer size 28, NALUs: 1 with frame_num=2


In the erroneous case, we get:
bitstream buffer size 805, NALUs: 7, 8, 6, 5 with frame_num=0
bitstream buffer size 28, NALUs: 1 with frame_num=2


which suggests that somehow, somewhere, the buffer size=23 with frame_num=1 could've been skipped/dropped in this case. The question is, why and where in the stack...
Cc: dalecur...@chromium.org
I tried to play the video in chrome (without seeking) and the video played to the end. In addition, there is only one SPS in the stream (as expected). So, it looks like one buffer is being dropped (as described in #6).

Hi Dale, do you know where the buffer could be dropped?
Cc: -dalecur...@chromium.org sande...@chromium.org
Owner: dalecur...@chromium.org
Status: Assigned (was: Started)
Is it possible that we could be making a decision in the renderer to drop an input buffer before sending it to VDA, perhaps to catch up?
We don't have any logic like that, but we do get bad metadata that causes us to do strange things occasionally.

In this case I'm doubting that, since the first buffer is the same in either case.

Is this a test I can reproduce on Mac?
Update: this reproduces on Mac. I modified h264_poc.cc to crash on gaps, and the test page reliably crashes (https://chromium.googlesource.com/chromiumos/third_party/autotest/+/HEAD/client/site_tests/video_VideoSeek/, note that control.h264 includes a link to the test media).

I have not fully reduced the test case yet (the randomness makes that tricky), so I am not sure which features of the seeking are critical. The test is most reliable with 10-20 'fast seeks' (seeks on 'seeking' event), which suggests that timing is a factor. I was not able to reproduce with 'fast seeks' turned off.

Reproduction is less reliable with the CancelPendingSeek() logic disabled, but I was still able to get occasional crashes.
Cc: wolenetz@chromium.org
+wolenetz@ I'd guess the new ffmpeg roll isn't seeking correctly.
@#12, I don't think the ffmpeg roll is implicated IIUC the original report's URL [1]: If indeed this was failing on **M56** prior to the roll actually merging to M56 last night (Nov 30 PM), then the failure pre-existed the roll.

[1] https://wmatrix.googleplex.com/unfiltered?hide_missing=True&tests=video_VideoSeek&days_back=45&releases=56
(I assume the releases=56 means this is M56. That assumption seems corroborated by the page that renders, showing failures back to at least October.)

ugh. s/Nov 30 PM/Nov 29 PM/ in c#13 :)
Components: -OS>Kernel>Video Internals>Media>Video
Labels: -OS-Chrome OS-All
Owner: sande...@chromium.org
Thanks Matt, looks like this issue has indeed existed for some time.
Project Member

Comment 16 by bugdroid1@chromium.org, Dec 5 2016

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

commit 216002cff0b287035a57cacc510419e15e5217c9
Author: sandersd <sandersd@chromium.org>
Date: Mon Dec 05 22:28:58 2016

media: Continue aborting FFMpegDemuxerStream::Read() calls until Seek().

For decoders that support multiple in-flight decodes (ie.
GpuVideoDecoder), it was possible to schedule a Read() after
AbortPendingReads() but before Seek() was called. These reads were
satisfied with data that decoders were not expecting (because the
aborted buffers were fully dropped, there were gaps in the input).

Now AbortPendingReads() is defined to continue to abort Read()s until
Seek(), which solves the problem. ChunkDemuxer was already implementing
this behavior, so only FFmpegDemuxer requires changes.

BUG= 667210 

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

[modify] https://crrev.com/216002cff0b287035a57cacc510419e15e5217c9/media/base/demuxer.h
[modify] https://crrev.com/216002cff0b287035a57cacc510419e15e5217c9/media/filters/ffmpeg_demuxer.cc
[modify] https://crrev.com/216002cff0b287035a57cacc510419e15e5217c9/media/filters/ffmpeg_demuxer.h
[modify] https://crrev.com/216002cff0b287035a57cacc510419e15e5217c9/media/filters/ffmpeg_demuxer_unittest.cc

wmatrix turned green on Dec 8 since R57-9062.0.0. Do you want to merge this to m56? If not, we can close this.
Labels: -videoshortlist
Labels: Merge-Request-56
This bug doesn't affect most platforms, but the patch is relatively simple. It's worth a try, but if there is any kind of merge issue I'll skip it.

Comment 20 by dimu@chromium.org, Jan 3 2017

Labels: -Merge-Request-56 Merge-Approved-56 Hotlist-Merge-Approved
Your change meets the bar and is auto-approved for M56 (branch: 2924)
Project Member

Comment 21 by bugdroid1@chromium.org, Jan 3 2017

Labels: -merge-approved-56 merge-merged-2924
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/3131222425a01a6b46f7e19f47b938200fda807d

commit 3131222425a01a6b46f7e19f47b938200fda807d
Author: Dan Sanders <sandersd@chromium.org>
Date: Tue Jan 03 22:25:18 2017

media: Continue aborting FFMpegDemuxerStream::Read() calls until Seek().

For decoders that support multiple in-flight decodes (ie.
GpuVideoDecoder), it was possible to schedule a Read() after
AbortPendingReads() but before Seek() was called. These reads were
satisfied with data that decoders were not expecting (because the
aborted buffers were fully dropped, there were gaps in the input).

Now AbortPendingReads() is defined to continue to abort Read()s until
Seek(), which solves the problem. ChunkDemuxer was already implementing
this behavior, so only FFmpegDemuxer requires changes.

BUG= 667210 

Review-Url: https://codereview.chromium.org/2546263002
Cr-Commit-Position: refs/heads/master@{#436428}
(cherry picked from commit 216002cff0b287035a57cacc510419e15e5217c9)

TBR=dalecurtis@chromium.org

Review-Url: https://codereview.chromium.org/2613623002 .
Cr-Commit-Position: refs/branch-heads/2924@{#658}
Cr-Branched-From: 3a87aecc31cd1ffe751dd72c04e5a96a1fc8108a-refs/heads/master@{#433059}

[modify] https://crrev.com/3131222425a01a6b46f7e19f47b938200fda807d/media/base/demuxer.h
[modify] https://crrev.com/3131222425a01a6b46f7e19f47b938200fda807d/media/filters/ffmpeg_demuxer.cc
[modify] https://crrev.com/3131222425a01a6b46f7e19f47b938200fda807d/media/filters/ffmpeg_demuxer.h
[modify] https://crrev.com/3131222425a01a6b46f7e19f47b938200fda807d/media/filters/ffmpeg_demuxer_unittest.cc

Status: Fixed (was: Assigned)

Sign in to add a comment