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

Issue 788387 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Last visit > 30 days ago
Closed: Dec 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Linux , Fuchsia
Pri: 2
Type: Bug



Sign in to add a comment

DCHECK failed in PipelineIntegrationTest.ReinitRenderersWhileVideoTrackIsDisabled

Project Member Reported by sheriff-...@appspot.gserviceaccount.com, Nov 24 2017

Issue description

media_unittests failing on chromium.memory/Linux CFI

Builders failed on: 
- Linux CFI: 
  https://build.chromium.org/p/chromium.memory/builders/Linux%20CFI

[ RUN      ] PipelineIntegrationTest.ReinitRenderersWhileVideoTrackIsDisabled
[23921:23921:1124/040236.017740:25198828057:FATAL:pipeline_impl.cc(559)] Check failed: !renderer_ended_.
...
#2 0x00000133d624 media::PipelineImpl::RendererWrapper::OnEnded()
#3 0x00000154b23f media::RendererImpl::RunEndedCallbackIfNeeded()
#4 0x00000154b09d media::RendererImpl::OnRendererEnded()
#5 0x000001552447 media::VideoRendererImpl::OnPlaybackEnded()
...
#14 0x00000171d4da base::RunLoop::Run()
#15 0x000001681d3a media::PipelineIntegrationTestBase::RunUntilIdleEndedOrErrorInternal()
#16 0x00000167f6ba media::PipelineIntegrationTestBase::WaitUntilCurrentTimeIsAfter()
#17 0x0000011c5f4a media::PipelineIntegrationTest_ReinitRenderersWhileVideoTrackIsDisabled_Test::TestBody()
 

Comment 1 by grt@chromium.org, Nov 24 2017

Components: Internals>Media>Video
Labels: OS-Linux
Owner: servolk@chromium.org
Status: Assigned (was: Available)
Project Member

Comment 2 by bugdroid1@chromium.org, Nov 24 2017

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

commit 31b9429100f7cae78e351cd0d51f51c86622f59d
Author: Greg Thompson <grt@chromium.org>
Date: Fri Nov 24 13:30:58 2017

Disable PipelineIntegrationTest.ReinitRenderersWhileVideoTrackIsDisabled on Linux due to flakes.

BUG= 788387 
TBR=grt@chromium.org
NOTRY=true

Change-Id: I88d2c737100038fe9f5123e0051d12776cdc3103
Reviewed-on: https://chromium-review.googlesource.com/788952
Reviewed-by: Greg Thompson <grt@chromium.org>
Commit-Queue: Greg Thompson <grt@chromium.org>
Cr-Commit-Position: refs/heads/master@{#519097}
[modify] https://crrev.com/31b9429100f7cae78e351cd0d51f51c86622f59d/media/test/pipeline_integration_test.cc

Comment 3 by grt@chromium.org, Nov 24 2017

Labels: -Sheriff-Chromium
This should just be made a non-clockless test probably, but as written the test is racy because it starts playback and expects to complete the test before the clip ends. 
Hmm, to be honest I don't understand why it was failing. Dale, could you explain?
What the test does is it suspends media playback momentarily (to force RendererImpl reinit) and then resumes it and waits until the playback position passes the 200ms mark. Given that the test file has a duration of 2.74 sec, why are we even reaching the OnEnded in the first place? Shouldn't WaitUntilCurrentTimeIsAfter exit much sooner than the end of stream is reached?
Btw, it's interesting that the test has suddenly become flaky on Nov 23. It's been added a long time ago and as far as I can see the previous ~100 test runs on the same builder were all successful, then there was suddenly 3 lakes in a row within ~8 hours starting on Nov 23 20:29 and then the test got disabled. I'm wondering if some other change in the media pipeline has somehow affected the test and made it flaky.
It's failing because the test uses clockless playback and Play() starts playback; which may complete before any other command executes. Even w/o clockless playback the test is likely flaky on QEMU bots or other very slow things because the second Play() is called playback has started and time is moving. If the rest of the test doesn't complete before it finishes it will fail.
I'm pretty sure it's started flaking since I switched all pipeline tests to clockless playback. As I indicated in c#4, we can switch it to non-clockless like a couple of other tests like this. It's still racy though.
FWIW I just ran this test on my workstation ~30 times at least and haven't seen a single failure. So unfortunately I don't have a good way to verify if clockless/non-clockless makes any difference.
A couple of observations:
1. The test failed due to this DCHECK https://cs.chromium.org/chromium/src/media/base/pipeline_impl.cc?rcl=aff60f657ecbd27573ec40d563d890124d43d03f&l=559 , which means that somehow OnEnded happened twice - that's suspicious. Even if the test is racy, the OnEnded shouldn't be triggered twice in the pipeline_impl
2. Probably unrelated issue, but I've noticed that AudioRendererImpl reports CurrentTimeValues past the stream duration. The test stream duration is 2.74 sec according to ffprobe, and the timestamp of the last audio frame is 2.744 sec, but audio renderer somehow reports timestamp of ~2.9 sec after processing EOS.

// Last audio frame
[193968:193968:1128/154436.179510:5875700709364:VERBOSE3:decoder_stream.cc(579)] OnBufferReady<audio>: 0, timestamp=2744000 duration=23000 size=1 side_data_size=0 is_key_frame=1 encrypted=0 discard_padding (ms)=(0, 0)

[193968:193968:1128/154436.180371:5875700710225:VERBOSE3:decoder_stream.cc(579)] OnBufferReady<audio>: 0, EOS


[193968:193968:1128/154436.181616:5875700711470:INFO:audio_renderer_impl.cc(198)] audio_clock_->front_timestamp=2.94469 s
[193968:193968:1128/154436.181671:5875700711524:INFO:audio_renderer_impl.cc(201)] adj audio_clock_->front_timestamp=2.94508 s
...
[193968:193968:1128/154436.191918:5875700721771:VERBOSE3:pipeline_impl.cc(1207)] GetMediaTime: 2955 ms

Comment 10 by w...@chromium.org, Dec 5 2017

Labels: M-65 OS-Fuchsia Type-Bug
We're seeing this flake on the new Fuchsia (FYI) bots as well. As per Dale's comment in #7, these are running under QEMU, so tend to be a little slower than running on a hugely multicore workstation.
Project Member

Comment 11 by bugdroid1@chromium.org, Dec 5 2017

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

commit 4bff19f2920d0cfb097c2a0ed10abddb13b676d0
Author: Sergey Ulanov <sergeyu@chromium.org>
Date: Tue Dec 05 18:56:20 2017

Disable ReinitRenderersWhileVideoTrackIsDisabled on all platforms

PipelineIntegrationTest.ReinitRenderersWhileVideoTrackIsDisabled was
disabled on Linux due to flake. It also fails periodically on Fuchsia.
Disabling it on all platforms.

Bug:  788387 
Change-Id: I85e3fc22361b355e0fc12ae26e3746d7bf6620c8
Reviewed-on: https://chromium-review.googlesource.com/809293
Reviewed-by: Dale Curtis <dalecurtis@chromium.org>
Commit-Queue: Sergey Ulanov <sergeyu@chromium.org>
Cr-Commit-Position: refs/heads/master@{#521767}
[modify] https://crrev.com/4bff19f2920d0cfb097c2a0ed10abddb13b676d0/media/test/pipeline_integration_test.cc

Project Member

Comment 12 by bugdroid1@chromium.org, Dec 5 2017

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

commit c0384943af8b5aa7ace8177eb195036b354f9d9c
Author: Sergey Ulanov <sergeyu@chromium.org>
Date: Tue Dec 05 22:05:07 2017

Fix and enable ReinitRenderersWhileVideoTrackIsDisabled

Added kNoClockless flag in the test. This is expected to fix the
flake.

Bug:  788387 
Change-Id: Ife4a443ef30d4f9b656e52ece3c1025cee5c0a96
Reviewed-on: https://chromium-review.googlesource.com/809507
Commit-Queue: Sergey Ulanov <sergeyu@chromium.org>
Reviewed-by: Dale Curtis <dalecurtis@chromium.org>
Cr-Commit-Position: refs/heads/master@{#521850}
[modify] https://crrev.com/c0384943af8b5aa7ace8177eb195036b354f9d9c/media/test/pipeline_integration_test.cc

Status: Fixed (was: Assigned)

Sign in to add a comment