New issue
Advanced search Search tips

Issue 835679 link

Starred by 4 users

Issue metadata

Status: Started
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

video_VideoSeek on Rockchip devices.

Project Member Reported by hiroh@chromium.org, Apr 23 2018

Issue description

video_VideoSeek sometimes fails on Rockchip devices, e.g., veyron_minnie and kevin.
It fails with "Error: Seek test is stuck and timeout", regardless of codec and test cases. 

https://cros-goldeneye.corp.google.com/chromeos/healthmonitoring/testDetails?testName=video_VideoSeek
 

Comment 1 by hiroh@chromium.org, Apr 23 2018

Cc: hiroh@chromium.org

Comment 2 by hiroh@chromium.org, Apr 23 2018

Cc: -acourbot@chromium.org
Owner: acourbot@chromium.org

Comment 3 by hiroh@chromium.org, May 7 2018

The thing becomes worse from 10635.0.0.
Some tests are broken from the same version.

Comment 5 by hiroh@chromium.org, May 7 2018

Cc: -hiroh@chromium.org acourbot@chromium.org
Owner: hiroh@chromium.org
Status: Started (was: Untriaged)

Comment 6 by hiroh@chromium.org, May 23 2018

Just looking the test log on failure.
Looks like VIDIOC_QBUF fails. I will try to reproduce this and investigate what happens there.

[17936:17936:0522/092037.047904:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1988)] Reset(): 
[17936:18470:0522/092037.049896:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1997)] ResetTask(): 
[17936:18470:0522/092037.050052:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1455)] FinishSurfaceSetChange(): 
[17936:18470:0522/092037.050894:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1455)] FinishSurfaceSetChange(): 
[17936:18470:0522/092037.051020:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(2051)] FinishReset(): Reset finished
[17936:17936:0522/092037.054781:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1988)] Reset(): 
[17936:18470:0522/092037.055328:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1997)] ResetTask(): 
[17936:18470:0522/092037.055570:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1455)] FinishSurfaceSetChange(): 
[17936:18470:0522/092037.056025:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1455)] FinishSurfaceSetChange(): 
[17936:18470:0522/092037.058731:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(1455)] FinishSurfaceSetChange(): 
[17936:18470:0522/092037.058974:VERBOSE2:v4l2_slice_video_decode_accelerator.cc(2051)] FinishReset(): Reset finished
[17936:18470:0522/092037.112462:VERBOSE1:v4l2_slice_video_decode_accelerator.cc(1155)] EnqueueInputRecord(): ioctl() failed: VIDIOC_QBUF: Invalid argument (22)
[17936:18470:0522/092037.112738:VERBOSE1:v4l2_slice_video_decode_accelerator.cc(960)] Enqueue(): Failed queueing an input buffer
[17936:18470:0522/092037.112861:VERBOSE1:v4l2_slice_video_decode_accelerator.cc(961)] Enqueue(): Setting error state: 4
[1:14:0522/092037.116516:ERROR:render_media_log.cc(30)] MediaEvent: MEDIA_ERROR_LOG_ENTRY {"error":"video decode error"}

Comment 7 by hiroh@chromium.org, May 24 2018

Cc: keiichiw@chromium.org hiroh@chromium.org
Labels: media-kernel-shortlist
Owner: tfiga@chromium.org
The error happens in vb2_internal_qbuf.
As far as I observed, the state can be VB2_BUF_STATE_REQUEUEING and VB2_BUF_STATE_ACTIVE.
That is, state machine can not be handled rightly with rockchip driver.
https://chromium.googlesource.com/chromiumos/third_party/kernel-next/+/chromeos-media-3.14/drivers/media/v4l2-core/videobuf2-core.c#1689

dmesg output on error.

[ 9943.747354] vb2: vb2_internal_dqbuf: dqbuf of buffer 11, with state 0
[ 9943.747485] vb2: vb2_internal_dqbuf: dqbuf of buffer 12, with state 0
[ 9943.747640] vb2: vb2_internal_dqbuf: dqbuf of buffer 13, with state 0
[ 9943.747774] vb2: vb2_internal_dqbuf: dqbuf of buffer 10, with state 0
[ 9943.747907] vb2: vb2_internal_dqbuf: dqbuf of buffer 9, with state 0
[ 9943.747978] vb2: vb2_internal_dqbuf: dqbuf of buffer 3, with state 0
[ 9943.748048] vb2: vb2_internal_dqbuf: dqbuf of buffer 0, with state 0
[ 9943.751132] vb2: vb2_internal_qbuf: qbuf of buffer 14 succeeded
[ 9943.751324] vb2: vb2_internal_qbuf: qbuf of buffer 2 succeeded
[ 9943.752123] vb2: vb2_internal_qbuf: qbuf of buffer 15 succeeded
[ 9943.752280] vb2: vb2_internal_qbuf: qbuf of buffer 7 succeeded
[ 9943.753367] vb2: vb2_internal_qbuf: invalid buffer state 5
[ 9943.756241] vb2: vb2_internal_dqbuf: dqbuf of buffer 14, with state 0
[ 9943.756383] vb2: vb2_internal_dqbuf: dqbuf of buffer 15, with state 0
[ 9943.756521] vb2: vb2_internal_dqbuf: dqbuf of buffer 2, with state 0
[ 9943.756795] vb2: vb2_internal_dqbuf: dqbuf of buffer 7, with state 0

Comment 8 by tfiga@chromium.org, May 31 2018

Status: Untriaged (was: Started)
Status: Assigned (was: Untriaged)
This bug has an owner, thus, it's been triaged. Changing status to "assigned".
Owner: ----
Status: Available (was: Assigned)
Project Member

Comment 11 by bugdroid1@chromium.org, Oct 2

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/autotest/+/390008e8b3c80c03f92afe0bd7d9b76e252b8823

commit 390008e8b3c80c03f92afe0bd7d9b76e252b8823
Author: Alexandre Courbot <acourbot@chromium.org>
Date: Tue Oct 02 16:17:30 2018

video_VideoSeek: improve timeout detection

The timeout detection simply consisted in triggering a timeout error if
the test took more than 180 seconds to complete. This can become a short
time to do 100 seeks, especially if the network conditions are not
optimal - as a result, many lab boards were reporting a timeout after
~70 iterations.

Fix this by doing the timeout check not on the whole test, but for each
individual seek: we consider a timeout has occured if we stay more than
60 seconds on the same seek.

BUG= chromium:822582 
BUG=chromium:835679
BUG= chromium:846239 
BUG= chromium:856171 
BUG=chromium:884583
BUG=b:62360942
TEST=Checked that the test completed succesfully on Eve.

Change-Id: I1d53a7a314b4a20e9f2be506a1bdf8e42de0c266
Reviewed-on: https://chromium-review.googlesource.com/1256582
Commit-Ready: Alexandre Courbot <acourbot@chromium.org>
Tested-by: Alexandre Courbot <acourbot@chromium.org>
Reviewed-by: Alexandre Courbot <acourbot@chromium.org>

[modify] https://crrev.com/390008e8b3c80c03f92afe0bd7d9b76e252b8823/client/site_tests/video_VideoSeek/video_VideoSeek.py

Project Member

Comment 12 by bugdroid1@chromium.org, Oct 5

Labels: merge-merged-release-R70-11021.B
The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/autotest/+/05874e747ce606225a1884763c23b119a2fa0dec

commit 05874e747ce606225a1884763c23b119a2fa0dec
Author: Alexandre Courbot <acourbot@chromium.org>
Date: Fri Oct 05 04:39:23 2018

video_VideoSeek: improve timeout detection

The timeout detection simply consisted in triggering a timeout error if
the test took more than 180 seconds to complete. This can become a short
time to do 100 seeks, especially if the network conditions are not
optimal - as a result, many lab boards were reporting a timeout after
~70 iterations.

Fix this by doing the timeout check not on the whole test, but for each
individual seek: we consider a timeout has occured if we stay more than
60 seconds on the same seek.

BUG= chromium:822582 
BUG=chromium:835679
BUG= chromium:846239 
BUG= chromium:856171 
BUG=chromium:884583
BUG=b:62360942
TEST=Checked that the test completed succesfully on Eve.

Change-Id: I1d53a7a314b4a20e9f2be506a1bdf8e42de0c266
Reviewed-on: https://chromium-review.googlesource.com/1256582
Commit-Ready: Alexandre Courbot <acourbot@chromium.org>
Tested-by: Alexandre Courbot <acourbot@chromium.org>
Reviewed-by: Alexandre Courbot <acourbot@chromium.org>
(cherry picked from commit 390008e8b3c80c03f92afe0bd7d9b76e252b8823)
Reviewed-on: https://chromium-review.googlesource.com/c/1264115
Commit-Queue: Alexandre Courbot <acourbot@chromium.org>

[modify] https://crrev.com/05874e747ce606225a1884763c23b119a2fa0dec/client/site_tests/video_VideoSeek/video_VideoSeek.py

Owner: acourbot@chromium.org
Status: Fixed (was: Available)
Closing as the fix has landed.
Status: Assigned (was: Verified)
Seems to be still happening.

Board: veyron_minnie
Build: 11155.0.0
Logs: https://stainless.corp.google.com/browse/chromeos-autotest-results/248228006-chromeos-test/chromeos4-row9-rack11-host20/

At the end of the debug logs:

10/13 17:51:46.628 DEBUG|inspector_websocke:0117| sent [{
  "id": 80, 
  "method": "Runtime.evaluate", 
  "params": {
    "expression": "getSeekTestStatus()", 
    "returnByValue": true
  }
}]
10/13 17:51:46.643 DEBUG|inspector_websocke:0188| got [{
  "id": 80, 
  "result": {
    "result": {
      "type": "string", 
      "value": "2.174141/4.8/30"
    }
  }
}]
10/13 17:51:46.644 INFO |   video_VideoSeek:0076| Seeking: 2.174141/4.8/30

This seek attempt repeats multiple times and finally it times out:

10/13 17:51:46.645 ERROR|             utils:2762| Will raise error TestError('Seek test is stuck and timeout',) due to unexpected return: False
Status: Started (was: Assigned)
Trying to get a local repro. In the meantime I will also try to change the test so that it fully downloads the video and then seek locally to rule out networking issues.
Got 186 pass on 200 local attempts of the test on Minnie, so it indeed looks like we have an issue with the driver of the VDA framework.

Sign in to add a comment