Investigating

The failure started in 11425.0.0 / 73.0.3644.0.
https://stainless.corp.google.com/search?view=matrix&row=model&col=build&first_date=2018-12-15&last_date=2018-12-28&test=video_VideoEncodeAccelerator&board=elm%7Chana&exclude_cts=false&exclude_not_run=false&exclude_non_release=false&exclude_au=true&exclude_acts=true&exclude_retried=true&exclude_non_production=false

CLs between 3640 and 3644: 
https://chromium.googlesource.com/chromium/src/+log/73.0.3640.0..73.0.3644.0?n=10000
4b80a24 media/gpu: Use VideoFrameLayout for format on input buffer. by Dean Liao · 10 days ago

Log:
https://00e9e64bacabacc61243f778378b1b0fd9ef7c16117a27a9cf-apidata.googleusercontent.com/download/storage/v1/b/chromeos-autotest-results/o/269625592-chromeos-test%2Fchromeos6-row4-rack2-host4%2Fdebug%2Fclient.0.DEBUG?qk=AD5uMEus9Jacio7RmnIsltx9mNnxzbwkl75I050RbAFlwbDfCf8tEnKJD_JO00zrU9OS59sYPHwh-km7CjV4ZQ0sjab9m0DelYD1uJI7VrF7nAknMHPfQ_IZHeDQX8hwCLQa3DwqA8HZtjnXMzpkY7B0ywAdMR2agIgcIrbjP9ctqBePfQgDxX3Zeqjb4Ij6L_KTzBO5V7lf9P11vi8JTnit_d67rQbH0jh2Qdgh1CfzoBTKTpY5auCxUXmU4HT5QEIvkMm0GROWxlc5_hR5VJ7yOXX6QYvQUDJZOX0AKgVynmvGL5UYHyU2u0hTuCA83ohmSO_yoJJ8uranzydiHwWU5D-rPy9OmNzGGWY1VmlbPAfA3bz5jGa9OH2MpGKyEP-7oQhBO-X6vREG6Bb0j2iyOKvifdOyL467hS6JLlTeieqCto27ykJ91g8zITbEXpEtKhUgd4GFVcAk1-MCDsV9fxy4b_D4zEvVudYc3ewo5rCIyHeA4lEXAQMOIgnK3c3-yV4wAQfzXY8OcZkPRxLYUNI5dbMsTF0kf1OqvVdWSFH3uLKUd-kaloffaz54L69KDs2_tWuCCVi5hvWkppUDSQnD1zTZFm57bcgxTiVp5bQGVeg1nfN31u3n3bbdncTsvloLPtn_FTskiZNq-neCPmlDTOhzpan4mri-_bQf43Mp4VVL3dFCtBhZn9pyFEMMnAh_nvZhy7rFbZhNQl7iWi3agiGN0tcbzSizFyJyup3nt7djHgGKq0nBJDKNrPeo77c4tLEm1sKxpHUuEhc5Dkfip1KllMSe4LLza-TYAkecP-S3-qdDX5owMldrGKCfCMviQisVCcB5xoVRP2TE63xtn7wWhHJOD9-a_iC9xtBpg7ygFAs

12/22 18:04:27.372 DEBUG|             utils:0287| [stdout] [----------] 1 test from SimpleEncode/VideoEncodeAcceleratorTest
12/22 18:04:27.372 DEBUG|             utils:0287| [stdout] [ RUN      ] SimpleEncode/VideoEncodeAcceleratorTest.TestSimpleEncode/0
12/22 18:04:27.373 ERROR|             utils:0287| [stderr] [6385:6390:1222/180427.343794:277057772:VERBOSE2:v4l2_video_encode_accelerator.cc(153)] Initialize(): : input_format: PIXEL_FORMAT_I420, input_visible_size: 320x192, output_profile: vp8, initial_bitrate: 200000, initial_framerate: 30
12/22 18:04:27.378 ERROR|             utils:0287| [stderr] [6385:6390:1222/180427.344025:277058001:VERBOSE2:v4l2_video_encode_accelerator.cc(183)] Initialize(): V4L2_ENC_CMD_STOP is not supported.
12/22 18:04:27.384 ERROR|             utils:0287| [stderr] [6385:6390:1222/180427.344051:277058027:VERBOSE2:v4l2_video_encode_accelerator.cc(1176)] SetFormats(): 
12/22 18:04:27.389 ERROR|             utils:0287| [stderr] [6385:6390:1222/180427.344438:277058414:VERBOSE2:v4l2_video_encode_accelerator.cc(1123)] NegotiateInputFormat(): 
12/22 18:04:27.395 ERROR|             utils:0287| [stderr] [6385:6390:1222/180427.344461:277058437:VERBOSE2:v4l2_video_encode_accelerator.cc(1143)] NegotiateInputFormat(): Trying S_FMT with YM12 (PIXEL_FORMAT_I420).
12/22 18:04:27.401 ERROR|             utils:0287| [stderr] [6385:6390:1222/180427.344487:277058463:VERBOSE2:v4l2_video_encode_accelerator.cc(1154)] NegotiateInputFormat(): Success: S_FMT with YM12
12/22 18:04:27.407 DEBUG|             utils:0287| [stdout] ../../../../../../../home/chrome-bot/chrome_root/src/media/gpu/video_encode_accelerator_unittest.cc:2457: Failure
12/22 18:04:27.408 DEBUG|             utils:0287| [stdout] Expected equality of these values:
12/22 18:04:27.408 DEBUG|             utils:0287| [stdout]   state
12/22 18:04:27.408 DEBUG|             utils:0287| [stdout]     Which is: 3
12/22 18:04:27.409 DEBUG|             utils:0287| [stdout]   notes[i]->Wait()
12/22 18:04:27.409 DEBUG|             utils:0287| [stdout]     Which is: 7
12/22 18:04:27.409 DEBUG|             utils:0287| [stdout] [  FAILED  ] SimpleEncode/VideoEncodeAcceleratorTest.TestSimpleEncode/0, where GetParam() = (1, true, 0, false, false, false, false, false, false) (59 ms)
12/22 18:04:27.412 DEBUG|             utils:0287| [stdout] [----------] 1 test from SimpleEncode/VideoEncodeAcceleratorTest (59 ms total)
12/22 18:04:27.412 DEBUG|             utils:0287| [stdout] 
12/22 18:04:27.413 DEBUG|             utils:0287| [stdout] [----------] 1 test from EncoderPerf/VideoEncodeAcceleratorTest
12/22 18:04:27.413 DEBUG|             utils:0287| [stdout] [ RUN      ] EncoderPerf/VideoEncodeAcceleratorTest.TestSimpleEncode/0
12/22 18:04:27.414 ERROR|             utils:0287| [stderr] [6385:6390:1222/180427.344509:277058484:VERBOSE2:v4l2_video_encode_accelerator.cc(1160)] Negotiated device_input_layout_: VideoFrameLayout(format: PIXEL_FORMAT_I420, coded_size: 320x192, planes (stride, offset, modifier): [(320, 0, 72057594037927935), (160, 0, 72057594037927935), (160, 0, 72057594037927935)], buffer_sizes: [71680, 17920, 17920])

The modifier value is strange. Is it wrong?

It failed at calling VIDIOC_QBUF. Looks like it queue same index twice before it is dequeued.

Command to reproduce:
/tmp/video/video_encode_accelerator_unittest --test_stream_data=/usr/local/video/tulip2-320x180-55be7124b3aec1b72bfb57f433297193.yuv:320:180:11:/usr/local/video/tulip2-320x180.yuv.out:100000:30:200000:30:1 --vmodule=*/media/gpu/*video_decode_accelerator.cc=2,*/media/gpu/*video_encode_accelerator.cc=4,*/media/gpu/*jpeg_decode_accelerator.cc=2,*/media/gpu/v4l2_image_processor.cc=2 --ozone-platform=gbm --gtest_filter=SimpleEncode*

[28015:28023:1227/214831.460733:22630266725:VERBOSE4:v4l2_video_encode_accelerator.cc(890)] EnqueueInputRecord():
[28015:28023:1227/214831.460769:22630266760:VERBOSE4:v4l2_video_encode_accelerator.cc(978)] EnqueueInputRecord(): Calling VIDIOC_QBUF: v4l2_buffer type: 10, memory: 2, index: 0 bytesused: 0, length: 3, m.planes[0](bytesused: 61440, length: 71680, data_offset: 0, m.userptr: 200337408), m.planes[1](bytesused: 15360, length: 17920, data_offset: 0, m.userptr: 200398848), m.planes[2](bytesused: 15360, length: 17920, data_offset: 0, m.userptr: 200414208)
[28015:28019:1227/214831.460829:22630266822:VERBOSE4:v4l2_video_encode_accelerator.cc(417)] UseOutputBitstreamBuffer(): id=501
[28015:28023:1227/214831.460966:22630266959:VERBOSE1:v4l2_video_encode_accelerator.cc(979)] EnqueueInputRecord(): ioctl() failed: VIDIOC_QBUF: Bad address (14)
[28015:28023:1227/214831.461023:22630267015:VERBOSE1:v4l2_video_encode_accelerator.cc(979)] EnqueueInputRecord(): Setting error state:2
[28015:28023:1227/214831.461059:22630267051:VERBOSE1:v4l2_video_encode_accelerator.cc(1104)] NotifyError(): error=2
[28015:28019:1227/214831.461130:22630267124:VERBOSE1:v4l2_video_encode_accelerator.cc(1104)] NotifyError(): error=2
[28015:28023:1227/214831.461126:22630267119:VERBOSE3:v4l2_video_encode_accelerator.cc(707)] ServiceDeviceTask(): 1] => DEVICE[1+1/2->1+1/2] => OUT[2]
[28015:28023:1227/214831.461200:22630267192:VERBOSE4:v4l2_video_encode_accelerator.cc(644)] UseOutputBitstreamBufferTask(): id=501
[28015:28024:1227/214831.461238:22630267232:VERBOSE4:v4l2_video_encode_accelerator.cc(1087)] DevicePollTask():
[28015:28023:1227/214831.461242:22630267237:VERBOSE4:v4l2_video_encode_accelerator.cc(720)] Enqueue(): free_input_buffers: 1input_queue: 1
[28015:28023:1227/214831.461290:22630267281:VERBOSE4:v4l2_video_encode_accelerator.cc(890)] EnqueueInputRecord():
[28015:28023:1227/214831.461325:22630267317:VERBOSE4:v4l2_video_encode_accelerator.cc(978)] EnqueueInputRecord(): Calling VIDIOC_QBUF: v4l2_buffer type: 10, memory: 2, index: 0 bytesused: 0, length: 3, m.planes[0](bytesused: 61440, length: 71680, data_offset: 0, m.userptr: 200337408), m.planes[1](bytesused: 15360, length: 17920, data_offset: 0, m.userptr: 200398848), m.planes[2](bytesused: 15360, length: 17920, data_offset: 0, m.userptr: 200414208)
../../media/gpu/video_encode_accelerator_unittest.cc:2457: Failure
Expected equality of these values:
  state
    Which is: 3
  notes[i]->Wait()
    Which is: 7

Deleted: vea_LATEST.log 1.2 MB

vea_LATEST.log 1.2 MB View Download

Note that for SimpleEncode, it is not always failed. Could be a race-related issue.

The root cause could be because input size parameter for RequireBitstreamBuffers were changed [1]

For VEA without image processor, it originally used |input_allocated_size_| which is initialized by [2]: V4L2Device::CodedSizeFromV4L2Format(format);

In elm and hana case, the new value |device_input_layout_->coded_size()| is obtained from device via S_FMT command. The coded size does not take additional paddings into account hence client allocate insufficient space for elm and hana VEA.

Why only hana VEA test fail but not elm? It is unclear yet.

Tentative solution would be keeping using input_allocated_size_ calculated by V4L2Device::CodedSizeFromV4L2Format(). However, the formula is not always correct. The ultimate solution is to pass input VideoFrameLayout to Client::RequireBitstreamBuffers to allocate correct input frame.

[1] https://chromium-review.googlesource.com/c/chromium/src/+/1361743/12/media/gpu/v4l2/v4l2_video_encode_accelerator.cc#299
[2] https://chromium-review.googlesource.com/c/chromium/src/+/1361743/12/media/gpu/v4l2/v4l2_video_encode_accelerator.cc#b1160

The ultimate fix is addressed in https://crbug.com/914700 media/gpu/v4l2 Use VideoFrameLayout to allocate frame

Let's take Hana encode 320x180 video as example:
After S_FMT input negotiation, its response v4l2_format struct:
pix_mp.width: 320
pix_mp.height: 192
bytesperline: 320
sizeimage: 107520

So in V4L2Device::CodedSizeFromV4L2Format:
coded_width = bytesperline * 8 / plane_horiz_bits_per_pixel = 320 * 8 / 8 = 320
coded_height = sizeimage * 8 / coded_width / total_bpp = 107520 * 8 / 320 / 12 = 224

And 320x224 is what Client::RequireBitstreamBuffers need to allocate sufficiently large input buffer for VEA to use.

Per discussion with Johny, of course it is better RequireBitstreamBuffers() takes VideoFrameLayout to allocate input buffer. But before the change is made, we may define GetAllocationSize() function in VideoFrameLayout. Johny think it is more clear to define size in three layers:
1. visible size: pixel width x height to be shown on screen (in this case 320x180)
2. coded size: codec aligned size (in this case, it is aligned to macro-block 16x16, which is 320x192)
3. driver allocation size: size required by driver (in this case, 320x224)

This should work in current board except Cheza. Cheza's VEA's requested sizeimage contains a constant padding (i.e. visible_size invariant) so its AllocationSize is unable to calculate correctly without knowing the size of constant padding. 

Take Cheza VEA as example (refer [1]), input size: 320x180, input format: NV12
1. visible size: 320x180
2. coded size: 320x192
3. allocation size: 384x213.3333...
(its negotiated bytesperline: 384, sizeimage: 122880)

[1] http://slides/11_EBx5hb8BcxGl_2yto8F2jpcavISEO4dglNWhZvUBU#slide=id.g3c9d6cb429_0_0

In my opinion V4L2Device::CodedSizeFromV4L2Format() is correct but misleading.

For now we are using VideoFrameLayout for V4L2VEA, in V4L2Device::V4L2FormatToVideoFrameLayout(), we treat pix_mp.width and pix.mp.height as "coded_size" (of VFL) [1]

However, in V4L2Device::CodedSizeFromV4L2Format(), pix_mp.width and pix_mp.height are treated as "visible_size" and have another way to get "coded_size" [2]

[1] https://cs.chromium.org/chromium/src/media/gpu/v4l2/v4l2_device.cc?dr=C&g=0&l=1334
[2] https://cs.chromium.org/chromium/src/media/gpu/v4l2/v4l2_device.cc?dr=C&g=0&l=1123

I suggest that we should at least change the function name to avoid misleading.

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

commit 8b3b147d1dda106428378474f87a56924f69651d
Author: Dean Liao <deanliao@chromium.org>
Date: Wed Jan 09 07:59:56 2019

media/gpu/v4l2 Fix input coded_size to request input buffer from client.

We currently use input VideoFrameLayout's coded_size to request input
buffer from client. However, we cannot correctly calcualte input buffer
size using VFL's coded_size as it does not consider padding and can
cause insufficient input buffer allocation.

Use coded_size calculated by V4L2Device::CodedSizeFromV4L2Format(format)
as parameter to call Client::RequireBitstreamBuffers can tentatively
solve the issue.

BUG= 918088 
TEST=Run VEA test on hana.

Change-Id: I9b17168884c3dc4699256f2248a79a1e1f7cce53
Reviewed-on: https://chromium-review.googlesource.com/c/1392699
Reviewed-by: Wu-Cheng Li <wuchengli@chromium.org>
Reviewed-by: Hirokazu Honda <hiroh@chromium.org>
Commit-Queue: Shuo-Peng Liao <deanliao@google.com>
Cr-Commit-Position: refs/heads/master@{#621072}
[modify] https://crrev.com/8b3b147d1dda106428378474f87a56924f69651d/media/gpu/v4l2/v4l2_device.cc
[modify] https://crrev.com/8b3b147d1dda106428378474f87a56924f69651d/media/gpu/v4l2/v4l2_device.h
[modify] https://crrev.com/8b3b147d1dda106428378474f87a56924f69651d/media/gpu/v4l2/v4l2_image_processor.cc
[modify] https://crrev.com/8b3b147d1dda106428378474f87a56924f69651d/media/gpu/v4l2/v4l2_video_encode_accelerator.cc
[modify] https://crrev.com/8b3b147d1dda106428378474f87a56924f69651d/media/gpu/v4l2/v4l2_video_encode_accelerator.h

Fixed. Stainless[1] showed that hana R73 didn't crash starting from R73-11566.0.0, which includes the commit [2] in Chrome 73.0.3667.0[3].

[1] https://stainless.corp.google.com/search?view=list&first_date=2019-01-08&last_date=2019-01-14&test=video_VideoEncodeAccelerator&board=hana&status=GOOD&status=FAIL&status=ERROR&exclude_cts=false&exclude_not_run=false&exclude_non_release=false&exclude_au=true&exclude_acts=true&exclude_retried=true&exclude_non_production=false
[2] https://crrev.com/8b3b147d1dda106428378474f87a56924f69651d
[3] https://chromium.googlesource.com/chromium/src/+log/73.0.3666.0..73.0.3667.0?n=10000