Protect access Pipeline::renderer_ with a lock.

Protect access to Pipeline::renderer_ with a lock.

During teardown it's possible to race calling Renderer::GetMediaTime()
on the main thread with ~Renderer() on the media thread.

This was introduced in be9da705e341863169faeff532c24c568fad2852 by
moving the TimeDeltaInterpolator (which used to never get destroyed)
into Renderer (which does get destroyed during error/stop).

BUG=411320
Committed: https://crrev.com/d3b784f65d7ff055b8e339ee607ebb59d6e692f1
Cr-Commit-Position: refs/heads/master@{#293577}

[scherkus (not reviewing), 2014-09-05 17:28:13]

scherkus@chromium.org changed reviewers:
+ xhwang@chromium.org

[scherkus (not reviewing), 2014-09-05 17:28:13]

I believe this works but I am afraid of running into deadlocks :\

Haven't ran into any so far on my machine but we'll see.

[xhwang, 2014-09-05 18:09:01]

On 2014/09/05 17:28:13, scherkus wrote:
> I believe this works but I am afraid of running into deadlocks :\
> 
> Haven't ran into any so far on my machine but we'll see.

During RendererImpl dtor, the init_cb_ or flush_cb_ could be fired. But the
callback for both is OnStateTransition(), which will do a post immediately, so
we shouldn't be running into deadlocks.

That being said, it's sad to add locking in more places. There are other
alternatives but those will be bigger change (e.g. always trigger DoStop() from
main thread, which requires changes in ErrorChangedTask). Also, can't wait to
refactor the whole GetMediaTime() craziness :)

lgtm

[scherkus (not reviewing), 2014-09-05 18:13:01]

On 2014/09/05 18:09:01, xhwang wrote:
> On 2014/09/05 17:28:13, scherkus wrote:
> > I believe this works but I am afraid of running into deadlocks :\
> > 
> > Haven't ran into any so far on my machine but we'll see.
> 
> During RendererImpl dtor, the init_cb_ or flush_cb_ could be fired. But the
> callback for both is OnStateTransition(), which will do a post immediately, so
> we shouldn't be running into deadlocks.
> 
> That being said, it's sad to add locking in more places. There are other
> alternatives but those will be bigger change (e.g. always trigger DoStop()
from
> main thread, which requires changes in ErrorChangedTask). Also, can't wait to
> refactor the whole GetMediaTime() craziness :)
> 
> lgtm

agreed -- I think we're stuck with some amount of locking until I wrap up my
changes inside of RendererImpl and we think through the right API for
informational time

[scherkus (not reviewing), 2014-09-05 18:13:07]

The CQ bit was checked by scherkus@chromium.org

[commit-bot: I haz the power, 2014-09-05 18:15:21]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/scherkus@chromium.org/545943004/1

[commit-bot: I haz the power, 2014-09-05 19:10:38]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2014-09-05 19:10:39]

Try jobs failed on following builders:
  android_clang_dbg_recipe on tryserver.chromium.linux
(http://build.chromium.org/p/tryserver.chromium.linux/builders/android_clang_d...)

[scherkus (not reviewing), 2014-09-05 19:22:08]

The CQ bit was checked by scherkus@chromium.org

[commit-bot: I haz the power, 2014-09-05 19:23:26]

CQ is trying da patch. Follow status at
 https://chromium-status.appspot.com/cq/scherkus@chromium.org/545943004/1

[commit-bot: I haz the power, 2014-09-05 21:01:09]

Committed patchset #1 (id:1) as 3ca727ccbd11817dbbc55af8b68ee9d5b7d5f212

[Nico, 2014-09-08 20:28:10]

This causes deadlocks:

http://build.chromium.org/p/chromium.memory.fyi/builders/Linux%20Tests%20%28T...

WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=13672)
  Cycle in lock order graph: M2062 (0x7d4c0000dc98) => M2052 (0x7d480000ba18) =>
M2062

  Mutex M2052 acquired here while holding mutex M2062 in main thread:
    #0 pthread_mutex_lock \u003Cnull>:0 (media_unittests+0x00000016fd70)
    #1 base::internal::LockImpl::Lock()
base/synchronization/lock_impl_posix.cc:45:12 (media_unittests+0x00000085ed59)
    #2 Acquire base/synchronization/lock.h:23:20
(media_unittests+0x0000006f60ee)
    #3 AutoLock base/synchronization/lock.h:99 (media_unittests+0x0000006f60ee)
    #4 media::Pipeline::GetMediaDuration() const media/base/pipeline.cc:175
(media_unittests+0x0000006f60ee)
    #5 Run base/bind_internal.h:153:12 (media_unittests+0x0000006f9382)
    #6 MakeItSo base/bind_internal.h:863 (media_unittests+0x0000006f9382)
    #7 base::internal::Invoker\u003C1,
base::internal::BindState\u003Cbase::internal::RunnableAdapter\u003Cbase::TimeDelta
(media::Pipeline::*)() const>, base::TimeDelta (media::Pipeline const*), void
(base::internal::UnretainedWrapper\u003Cmedia::Pipeline>)>, base::TimeDelta
(media::Pipeline const*)>::Run(base::internal::BindStateBase*)
base/bind_internal.h:1166 (media_unittests+0x0000006f9382)
    #8 Run base/callback.h:401:12 (media_unittests+0x000000760875)
    #9 media::RendererImpl::GetMediaDuration()
media/filters/renderer_impl.cc:187 (media_unittests+0x000000760875)
    #10 Run base/bind_internal.h:134:12 (media_unittests+0x0000007620c2)
    #11 MakeItSo base/bind_internal.h:863 (media_unittests+0x0000007620c2)
    #12 base::internal::Invoker\u003C1,
base::internal::BindState\u003Cbase::internal::RunnableAdapter\u003Cbase::TimeDelta
(media::RendererImpl::*)()>, base::TimeDelta (media::RendererImpl*), void
(base::internal::UnretainedWrapper\u003Cmedia::RendererImpl>)>, base::TimeDelta
(media::RendererImpl*)>::Run(base::internal::BindStateBase*)
base/bind_internal.h:1166 (media_unittests+0x0000007620c2)
    #13 Run base/callback.h:401:12 (media_unittests+0x00000077bafa)
    #14 AddReadyFrame_Locked media/filters/video_renderer_impl.cc:401
(media_unittests+0x00000077bafa)
    #15
media::VideoRendererImpl::FrameReady(media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status,
scoped_refptr\u003Cmedia::VideoFrame> const&)
media/filters/video_renderer_impl.cc:340 (media_unittests+0x00000077bafa)
    #16 Run base/bind_internal.h:248:12 (media_unittests+0x00000077c218)
    #17 MakeItSo base/bind_internal.h:938 (media_unittests+0x00000077c218)
    #18 base::internal::Invoker\u003C1,
base::internal::BindState\u003Cbase::internal::RunnableAdapter\u003Cvoid
(media::VideoRendererImpl::*)(media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status,
scoped_refptr\u003Cmedia::VideoFrame> const&)>, void (media::VideoRendererImpl*,
media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status,
scoped_refptr\u003Cmedia::VideoFrame> const&), void
(base::WeakPtr\u003Cmedia::VideoRendererImpl>)>, void
(media::VideoRendererImpl*,
media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status,
scoped_refptr\u003Cmedia::VideoFrame>
const&)>::Run(base::internal::BindStateBase*,
media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status const&,
scoped_refptr\u003Cmedia::VideoFrame> const&) base/bind_internal.h:1310
(media_unittests+0x00000077c218)
    #19 Run base/callback.h:483:12 (media_unittests+0x000000732dcf)
    #20 SatisfyRead media/filters/decoder_stream.cc:249
(media_unittests+0x000000732dcf)
    #21
media::DecoderStream\u003C(media::DemuxerStream::Type)2>::OnDecodeOutputReady(scoped_refptr\u003Cmedia::VideoFrame>
const&) media/filters/decoder_stream.cc:377 (media_unittests+0x000000732dcf)
    #22 Run base/bind_internal.h:190:12 (media_unittests+0x000000739811)
    #23 MakeItSo base/bind_internal.h:909 (media_unittests+0x000000739811)
    #24 base::internal::Invoker\u003C1,
base::internal::BindState\u003Cbase::internal::RunnableAdapter\u003Cvoid
(media::DecoderStream\u003C(media::DemuxerStream::Type)2>::*)(scoped_refptr\u003Cmedia::VideoFrame>
const&)>, void (media::DecoderStream\u003C(media::DemuxerStream::Type)2>*,
scoped_refptr\u003Cmedia::VideoFrame> const&), void
(base::WeakPtr\u003Cmedia::DecoderStream\u003C(media::DemuxerStream::Type)2>
>)>, void (media::DecoderStream\u003C(media::DemuxerStream::Type)2>*,
scoped_refptr\u003Cmedia::VideoFrame>
const&)>::Run(base::internal::BindStateBase*,
scoped_refptr\u003Cmedia::VideoFrame> const&) base/bind_internal.h:1219
(media_unittests+0x000000739811)


  Mutex M2062 previously acquired by the same thread here:
    #0 pthread_mutex_lock \u003Cnull>:0 (media_unittests+0x00000016fd70)
    #1 base::internal::LockImpl::Lock()
base/synchronization/lock_impl_posix.cc:45:12 (media_unittests+0x00000085ed59)
    #2 Acquire base/synchronization/lock.h:23:20
(media_unittests+0x00000077b811)
    #3 AutoLock base/synchronization/lock.h:99 (media_unittests+0x00000077b811)
    #4
media::VideoRendererImpl::FrameReady(media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status,
scoped_refptr\u003Cmedia::VideoFrame> const&)
media/filters/video_renderer_impl.cc:302 (media_unittests+0x00000077b811)
    #5 Run base/bind_internal.h:248:12 (media_unittests+0x00000077c218)
    #6 MakeItSo base/bind_internal.h:938 (media_unittests+0x00000077c218)
    #7 base::internal::Invoker\u003C1,
base::internal::BindState\u003Cbase::internal::RunnableAdapter\u003Cvoid
(media::VideoRendererImpl::*)(media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status,
scoped_refptr\u003Cmedia::VideoFrame> const&)>, void (media::VideoRendererImpl*,
media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status,
scoped_refptr\u003Cmedia::VideoFrame> const&), void
(base::WeakPtr\u003Cmedia::VideoRendererImpl>)>, void
(media::VideoRendererImpl*,
media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status,
scoped_refptr\u003Cmedia::VideoFrame>
const&)>::Run(base::internal::BindStateBase*,
media::DecoderStream\u003C(media::DemuxerStream::Type)2>::Status const&,
scoped_refptr\u003Cmedia::VideoFrame> const&) base/bind_internal.h:1310
(media_unittests+0x00000077c218)
    #8 Run base/callback.h:483:12 (media_unittests+0x000000732dcf)
    #9 SatisfyRead media/filters/decoder_stream.cc:249
(media_unittests+0x000000732dcf)
    #10
media::DecoderStream\u003C(media::DemuxerStream::Type)2>::OnDecodeOutputReady(scoped_refptr\u003Cmedia::VideoFrame>
const&) media/filters/decoder_stream.cc:377 (media_unittests+0x000000732dcf)


  Mutex M2062 acquired here while holding mutex M2052 in main thread:
    #0 pthread_mutex_lock \u003Cnull>:0 (media_unittests+0x00000016fd70)
    #1 base::internal::LockImpl::Lock()
base/synchronization/lock_impl_posix.cc:45:12 (media_unittests+0x00000085ed59)
    #2 Acquire base/synchronization/lock.h:23:20
(media_unittests+0x000000779478)
    #3 AutoLock base/synchronization/lock.h:99 (media_unittests+0x000000779478)
    #4 media::VideoRendererImpl::~VideoRendererImpl()
media/filters/video_renderer_impl.cc:55 (media_unittests+0x000000779478)
    #5 media::VideoRendererImpl::~VideoRendererImpl()
media/filters/video_renderer_impl.cc:51:41 (media_unittests+0x000000779809)
    #6 operator() base/memory/scoped_ptr.h:137:5
(media_unittests+0x00000075f42d)
    #7 reset base/memory/scoped_ptr.h:246 (media_unittests+0x00000075f42d)
    #8 reset base/memory/scoped_ptr.h:367 (media_unittests+0x00000075f42d)
    #9 media::RendererImpl::~RendererImpl() media/filters/renderer_impl.cc:50
(media_unittests+0x00000075f42d)
    #10 media::RendererImpl::~RendererImpl()
media/filters/renderer_impl.cc:45:31 (media_unittests+0x00000075f6d9)
    #11 operator() base/memory/scoped_ptr.h:137:5
(media_unittests+0x0000006f8133)
    #12 reset base/memory/scoped_ptr.h:246 (media_unittests+0x0000006f8133)
    #13 reset base/memory/scoped_ptr.h:367 (media_unittests+0x0000006f8133)
    #14 media::Pipeline::DoStop(base::Callback\u003Cvoid
(media::PipelineStatus)> const&) media/base/pipeline.cc:410
(media_unittests+0x0000006f8133)
    #15 media::Pipeline::StopTask(base::Callback\u003Cvoid ()> const&)
media/base/pipeline.cc:526:3 (media_unittests+0x0000006f52e1)


  Mutex M2052 previously acquired by the same thread here:
    #0 pthread_mutex_lock \u003Cnull>:0 (media_unittests+0x00000016fd70)
    #1 base::internal::LockImpl::Lock()
base/synchronization/lock_impl_posix.cc:45:12 (media_unittests+0x00000085ed59)
    #2 Acquire base/synchronization/lock.h:23:20
(media_unittests+0x0000006f80fb)
    #3 AutoLock base/synchronization/lock.h:99 (media_unittests+0x0000006f80fb)
    #4 media::Pipeline::DoStop(base::Callback\u003Cvoid (media::PipelineStatus)>
const&) media/base/pipeline.cc:409 (media_unittests+0x0000006f80fb)
    #5 media::Pipeline::StopTask(base::Callback\u003Cvoid ()> const&)
media/base/pipeline.cc:526:3 (media_unittests+0x0000006f52e1)
    #6 Run base/bind_internal.h:190:12 (media_unittests+0x0000006fb730)
    #7 MakeItSo base/bind_internal.h:909 (media_unittests+0x0000006fb730)

[Nico, 2014-09-08 21:02:23]

The bug 403s for me. How serious is the bug this fixes? More serious than a
deadlock? Should we revert this change while this is being fixed?

[DaleCurtis, 2014-09-08 21:04:54]

dalecurtis@chromium.org changed reviewers:
+ dalecurtis@chromium.org

[DaleCurtis, 2014-09-08 21:04:54]

Added you to the bug.  scherkus: What do you want to do?

[scherkus (not reviewing), 2014-09-09 00:49:08]

On 2014/09/08 21:04:54, DaleCurtis wrote:
> Added you to the bug.  scherkus: What do you want to do?

fix it imo! https://codereview.chromium.org/557603002

[commit-bot: I haz the power, 2014-09-10 03:41:27]

Patchset 1 (id:??) landed as
https://crrev.com/d3b784f65d7ff055b8e339ee607ebb59d6e692f1
Cr-Commit-Position: refs/heads/master@{#293577}