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

Issue 638554 link

Starred by 2 users

Issue metadata

Status: WontFix
Owner:
Last visit > 30 days ago
Closed: Feb 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 2
Type: Bug



Sign in to add a comment

WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp9 flaky (times out) on chromium.webrtc Win8 Tester

Project Member Reported by olka@chromium.org, Aug 17 2016

Issue description

Example:
https://build.chromium.org/p/chromium.webrtc/builders/Win8%20Tester/builds/27624/steps/browser_tests/logs/stdio

[876:3128:0817/034334:WARNING:vp9_frame_buffer_pool.cc(72)] 11 Vp9FrameBuffers have been allocated by a Vp9FrameBufferPool (exceeding what is considered reasonable, 10).


#
# Fatal error in e:\b\c\b\win_builder\src\third_party\webrtc\modules\video_coding\codecs\vp9\vp9_frame_buffer_pool.cc, line 76
# last system error: 0
# Check failed: false
# 
#
[4532:5040:0817/034334:ERROR:browser_test_utils.cc(177)] Cannot communicate with DOMOperationObserver.
[4532:5040:0817/034334:ERROR:webrtc_browsertest_common.cc(157)] Failed to sleep.
[4532:3704:0817/034334:WARNING:audio_sync_reader.cc(132)] AudioSyncReader::Read timed out, audio glitch count=1
[4532:1080:0817/034334:WARNING:audio_sync_reader.cc(132)] AudioSyncReader::Read timed out, audio glitch count=1
[1196:1992:0817/034337:WARNING:rtp_rtcp_impl.cc(155)] webrtc::ModuleRtpRtcpImpl::Process: Timeout: No RTCP RR received.
[1196:1992:0817/034337:WARNING:rtp_rtcp_impl.cc(157)] webrtc::ModuleRtpRtcpImpl::Process: Timeout: No increase in RTCP RR extended highest sequence number.
[98/98] WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp9/1 (TIMED OUT)

Some other examples:
https://build.chromium.org/p/chromium.webrtc/builders/Win8%20Tester/builds/27606/steps/browser_tests/logs/stdio
https://build.chromium.org/p/chromium.webrtc/builders/Win8%20Tester/builds/27561/steps/browser_tests/logs/stdio

 
Cc: holmer@chromium.org mflodman@chromium.org
Components: Blink>WebRTC>Video
Owner: hbos@chromium.org
Henrik (as CL author), Stefan (as CL reviewer),
Can you give some context to this NOT_RAECHED and how 10 was set as "considered reasonable"?

Are these buffers used while waiting for correct render time or what is the expected lifetime of these frames?

Comment 2 by hbos@chromium.org, Aug 17 2016

Oh, this was a long time ago.

When I wrote this code I had found based on testing that ~3-4 frame buffers were typically referenced by libvpx at a time.
A buffer is not returned to the pool until it's no longer referenced[1], and a reference to every decoded frame is given to a DecodedImageCallback[2]. If we continue to decode more frames before dereferencing previous buffers the number of buffers allocated and in use will increase. If we exceed 10 buffers we hit this check.

It may be the case that with other settings or under other circumstances libvpx will hold on to more frames than the previously observed ~3-4 frames. Or it may be the case that the frame is delivered to something that is holding on to the frames for a longer duration than the Decoded() call.

I think 10 was chosen somewhat arbitrarily under the assumption that libvpx needs at most 4 buffers in order to look at past frames and that the Decoded() callback would not hog references.

If frames are jumping threads or rendering may be delayed for other reasons, 10 might not be a reasonable number. I don't know exactly what happens to the buffers at Decoded() or if libvpx could want more than 4 buffers.

A simple fix would be to increase this number, but then we risk hiding a possible performance regression.

[1] https://cs.chromium.org/chromium/src/third_party/webrtc/modules/video_coding/codecs/vp9/vp9_impl.cc?sq=package:chromium&dr&rcl=1471410508&l=962
[2] https://cs.chromium.org/chromium/src/third_party/webrtc/modules/video_coding/codecs/vp9/vp9_impl.cc?sq=package:chromium&dr&rcl=1471410508&l=967
Status: Assigned (was: Untriaged)
Assigning this to you hbos

Comment 4 by hta@chromium.org, Aug 29 2016

VP9 is defined to have 8 reference buffers, of which 3 can be referenced by any frame (I heard 16 at one point, but the draft that Adrian wrote says 8).
https://tools.ietf.org/html/draft-grange-vp9-bitstream-00

I suspect the number of reference buffers actually used depends on settings.

Comment 5 by hbos@chromium.org, Aug 29 2016

Thanks hta, I updated by CL based on that information (https://codereview.webrtc.org/2280593002/).
Project Member

Comment 6 by bugdroid1@chromium.org, Sep 6 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/external/webrtc.git/+/c928453fd03a25d9d66d1c5052fcd1e4ade3dbc7

commit c928453fd03a25d9d66d1c5052fcd1e4ade3dbc7
Author: hbos <hbos@webrtc.org>
Date: Tue Sep 06 08:38:28 2016

Significantly increased max_num_buffers_ of Vp9FrameBufferPool.

Changed from 10 to 68.

This is to avoid a flake where the limit is exceeded, see
 crbug.com/638554 . Our performance tests should flag performance
regressions, we shouldn't rely on crashing because the number of
referenced buffers is not tiny to detect this. However, if a really big
number of buffers (>68) are referenced without being dereferenced it is
likely that we have a bug and frames are leaking in which case we can
DCHECK-crash.

BUG= chromium:638554 

Review-Url: https://codereview.webrtc.org/2280593002
Cr-Commit-Position: refs/heads/master@{#14084}

[modify] https://crrev.com/c928453fd03a25d9d66d1c5052fcd1e4ade3dbc7/webrtc/modules/video_coding/codecs/vp9/vp9_frame_buffer_pool.h

Comment 7 by hbos@chromium.org, Sep 6 2016

Status: Fixed (was: Assigned)

Comment 8 by hbos@chromium.org, Sep 27 2016

Cc: hbos@chromium.org
Owner: ----
Status: Available (was: Fixed)
It just happened again after the limit was increased:
https://build.chromium.org/p/chromium.webrtc.fyi/builders/Win10%20Tester/builds/4477/steps/browser_tests/logs/stdio
Owner: brandtr@chromium.org
Status: Assigned (was: Available)
Rasmus, do you have someone to assign this to? I think it would be good to look into.
Owner: ehmaldonado@chromium.org
I don't think the flake in #9 is a codec problem, but rather something with the test or the infrastructure; see logs below.

ehmaldonado, would you mind taking a look or reassign to somebody more appropriate?

==

4 tests failed:
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityH264/0 (e:\b\c\b\win_builder\src\chrome\browser\media\webrtc\webrtc_video_quality_browsertest.cc:344)
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityH264/1 (e:\b\c\b\win_builder\src\chrome\browser\media\webrtc\webrtc_video_quality_browsertest.cc:344)
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp8/1 (e:\b\c\b\win_builder\src\chrome\browser\media\webrtc\webrtc_video_quality_browsertest.cc:344)
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp9/1 (e:\b\c\b\win_builder\src\chrome\browser\media\webrtc\webrtc_video_quality_browsertest.cc:344)

==

WARNING: Using deprecated switch --stats_file. The new flag is --stats_file_test.
Converting YUV file to PNG images (may take a while)...
C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\ffmpeg.exe -s 1280x720 -i C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\reference_video_1280x720_30fps.yuv -f image2 -vcodec png c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_%04d.png
Decoding barcodes from PNG files with C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe...
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0003.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0003.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0003.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0005.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0005.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0005.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0006.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0006.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0006.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0007.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0007.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0007.png: command returned -1073741502 and printed  and 
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0010.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0010.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0010.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0011.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0011.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0011.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0012.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0012.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0012.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0014.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0014.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0014.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0015.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0015.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0015.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0016.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0016.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0016.png: command returned -1073741502 and printed  and 
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0017.png
Barcode in c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0017.png cannot be decoded.
Failed to run C:\b\c\b\Win10_Tester\src\chrome\test\data\webrtc/resources\tools\win\zxing.exe --try-harder --dump-raw c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0017.png: command returned -1073741502 and printed  and 
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
At least one action <function _DecodeBarcodeInFile at 0x028DC8B0> failed for files frame_xxxx.png.
Error during decoding of c:\users\chrome~2\appdata\local\temp\tmpt8jcka\frame_0023.png
Something similar happened again, this time on Android:

https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Fchromium.webrtc.fyi%2FMac_Tester%2F40781%2F%2B%2Frecipes%2Fsteps%2Fbrowser_tests%2F0%2Fstdout

==

[11402:775:0630/041928.803005:ERROR:webrtc_video_quality_browsertest.cc(255)] Failed to compare videos; see output above to see what the error was.
Output was:
Usage: compare_videos.py [options]
compare_videos.py: error: You must provide a path to the reference video!
../../chrome/browser/media/webrtc/webrtc_video_quality_browsertest.cc:315: Failure
Value of: CompareVideosAndPrintResult( MakeLabel(test_config_.test_name, video_codec), test_config_.width, test_config_.height, GetWorkingDir().Append(kCapturedYuvFileName), test::GetReferenceFilesDir() .Append(test_config_.reference_video) .AddExtension(test::kYuvFileExtension), GetWorkingDir().Append(kStatsFileName))
  Actual: false
Expected: true

==

[  FAILED  ] WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp9/1, where GetParam() = 32-byte object <45-24 72-19 01-00 00-00 00-05 00-00 D0-02 00-00 90-4A 01-19 01-00 00-00 00-4A 01-19 01-00 00-00> (10026 ms)
[74/74] WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp9/1 (10259 ms)
6 tests failed:
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityH264/0 (../../chrome/browser/media/webrtc/webrtc_video_quality_browsertest.cc:344)
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityH264/1 (../../chrome/browser/media/webrtc/webrtc_video_quality_browsertest.cc:344)
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp8/0 (../../chrome/browser/media/webrtc/webrtc_video_quality_browsertest.cc:344)
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp8/1 (../../chrome/browser/media/webrtc/webrtc_video_quality_browsertest.cc:344)
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp9/0 (../../chrome/browser/media/webrtc/webrtc_video_quality_browsertest.cc:344)
    WebRtcVideoQualityBrowserTests/WebRtcVideoQualityBrowserTest.MANUAL_TestVideoQualityVp9/1 (../../chrome/browser/media/webrtc/webrtc_video_quality_browsertest.cc:344)
Owner: phoglund@chromium.org
Status: WontFix (was: Assigned)
The last observed flake was in June, and that one sounds like someone made a bad commit so paths don't propagate properly. That must have been reverted or fixed pretty quickly.

I took a quick glance at the FYI bots and I can't see any flakes at all recently, so I will assume this is fine now.

Sign in to add a comment