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

Issue 797966 link

Starred by 1 user

Issue metadata

Status: Verified
Owner:
Closed: Jan 2018
Cc:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 3
Type: Bug



Sign in to add a comment

ThreadSanitizer reports a potential deadlock in TracingControllerTest.EnableAndStopTracingWithCompression

Project Member Reported by glider@chromium.org, Dec 28 2017

Issue description

See https://chromium-swarm.appspot.com/task?id=3ab65b9b7d4a4a10&refresh=10&show_raw=1

[ RUN      ] TracingControllerTest.EnableAndStopTracingWithCompression
Xlib:  extension "RANDR" missing on display ":99".

DevTools listening on ws://127.0.0.1:60251/devtools/browser/b4610760-1e91-49c3-b3b4-5ebf91539b5e
Fontconfig warning: "/etc/fonts/fonts.conf", line 146: blank doesn't take any effect anymore. please remove it from your fonts.conf
==================
WARNING: ThreadSanitizer: lock-order-inversion (potential deadlock) (pid=15472)
  Cycle in lock order graph: M2515 (0x7b6400000510) => M2514 (0x7b5400000410) => M2414 (0x7b5c00000388) => M2515

  Mutex M2514 acquired here while holding mutex M2515 in thread T6:
    #0 pthread_mutex_lock /b/build/slave/linux_upload_clang/build/src/third_party/llvm/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:3801:3 (content_browsertests+0x1645d2e)
    #1 base::internal::LockImpl::Lock() base/synchronization/lock_impl_posix.cc:73:12 (content_browsertests+0x45c635d)
    #2 Acquire base/synchronization/lock.h:26:26 (content_browsertests+0x3590b93)
    #3 MoveableAutoLock third_party/WebKit/Source/platform/scheduler/base/moveable_auto_lock.h:16 (content_browsertests+0x3590b93)
    #4 blink::scheduler::TaskQueueManager::OnQueueHasIncomingImmediateWork(blink::scheduler::internal::TaskQueueImpl*, unsigned long, bool) third_party/WebKit/Source/platform/scheduler/base/task_queue_manager.cc:188 (content_browsertests+0x3590b93)
    #5 blink::scheduler::internal::TaskQueueImpl::PushOntoImmediateIncomingQueueLocked(blink::scheduler::internal::TaskQueueImpl::Task) third_party/WebKit/Source/platform/scheduler/base/task_queue_impl.cc:313:38 (content_browsertests+0x358830a)
    #6 blink::scheduler::internal::TaskQueueImpl::PostImmediateTaskImpl(blink::scheduler::TaskQueue::PostedTask) third_party/WebKit/Source/platform/scheduler/base/task_queue_impl.cc:190:3 (content_browsertests+0x3587c5f)
    #7 blink::scheduler::internal::TaskQueueImpl::PostDelayedTask(blink::scheduler::TaskQueue::PostedTask) third_party/WebKit/Source/platform/scheduler/base/task_queue_impl.cc:174:12 (content_browsertests+0x3587a4f)
    #8 blink::scheduler::TaskQueue::PostDelayedTask(base::Location const&, base::OnceCallback<void ()>, base::TimeDelta) third_party/WebKit/Source/platform/scheduler/base/task_queue.cc:75:17 (content_browsertests+0x35863f3)
    #9 base::TaskRunner::PostTask(base::Location const&, base::OnceCallback<void ()>) base/task_runner.cc:44:10 (content_browsertests+0x45ccc2a)
    #10 service_manager::CallbackBinder<content::mojom::ChildControl>::BindInterface(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>) services/service_manager/public/cpp/interface_binder.h:58:21 (content_browsertests+0x6335b08)
    #11 service_manager::BinderRegistryWithArgs<>::BindInterface(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>) services/service_manager/public/cpp/binder_registry.h:86:19 (content_browsertests+0x1d629df)
    #12 TryBindInterface services/service_manager/public/cpp/binder_registry.h:115:7 (content_browsertests+0x1f2c330)
    #13 content::SimpleConnectionFilter::OnBindInterface(service_manager::BindSourceInfo const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>*, service_manager::Connector*) content/public/common/simple_connection_filter.cc:20 (content_browsertests+0x1f2c330)
    #14 content::ServiceManagerConnectionImpl::IOThreadContext::OnBindInterface(service_manager::BindSourceInfo const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>) content/common/service_manager/service_manager_connection_impl.cc:265:23 (content_browsertests+0x24636a6)
    #15 service_manager::ForwardingService::OnBindInterface(service_manager::BindSourceInfo const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>) services/service_manager/public/cpp/service.cc:48:12 (content_browsertests+0x4231b55)
    #16 service_manager::ServiceContext::OnBindInterface(service_manager::BindSourceInfo const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>, base::OnceCallback<void ()>) services/service_manager/public/cpp/service_context.cc:143:13 (content_browsertests+0x4232c39)
    #17 service_manager::mojom::ServiceStubDispatch::AcceptWithResponder(service_manager::mojom::Service*, mojo::Message*, std::__1::unique_ptr<mojo::MessageReceiverWithStatus, std::__1::default_delete<mojo::MessageReceiverWithStatus> >) out/Release/gen/services/service_manager/public/interfaces/service.mojom.cc:524:13 (content_browsertests+0x4e0d778)
    #18 service_manager::mojom::ServiceStub<mojo::RawPtrImplRefTraits<service_manager::mojom::Service> >::AcceptWithResponder(mojo::Message*, std::__1::unique_ptr<mojo::MessageReceiverWithStatus, std::__1::default_delete<mojo::MessageReceiverWithStatus> >) out/Release/gen/services/service_manager/public/interfaces/service.mojom.h:173:12 (content_browsertests+0x4233991)
    #19 mojo::InterfaceEndpointClient::HandleValidatedMessage(mojo::Message*) mojo/public/cpp/bindings/lib/interface_endpoint_client.cc:394:34 (content_browsertests+0x41f1533)
    #20 mojo::InterfaceEndpointClient::HandleIncomingMessageThunk::Accept(mojo::Message*) mojo/public/cpp/bindings/lib/interface_endpoint_client.cc:133:18 (content_browsertests+0x41f125a)
    #21 mojo::FilterChain::Accept(mojo::Message*) mojo/public/cpp/bindings/lib/filter_chain.cc:40:17 (content_browsertests+0x41f0c7d)
    #22 mojo::InterfaceEndpointClient::HandleIncomingMessage(mojo::Message*) mojo/public/cpp/bindings/lib/interface_endpoint_client.cc:306:19 (content_browsertests+0x41f2854)
    #23 mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::internal::MultiplexRouter::MessageWrapper*, mojo::internal::MultiplexRouter::ClientCallBehavior, base::SequencedTaskRunner*) mojo/public/cpp/bindings/lib/multiplex_router.cc:880:42 (content_browsertests+0x41ff019)
    #24 mojo::internal::MultiplexRouter::Accept(mojo::Message*) mojo/public/cpp/bindings/lib/multiplex_router.cc:604:38 (content_browsertests+0x41fe2d7)
    #25 mojo::FilterChain::Accept(mojo::Message*) mojo/public/cpp/bindings/lib/filter_chain.cc:40:17 (content_browsertests+0x41f0c7d)
    #26 mojo::Connector::ReadSingleMessage(unsigned int*) mojo/public/cpp/bindings/lib/connector.cc:445:51 (content_browsertests+0x41ef7a5)
    #27 mojo::Connector::ReadAllAvailableMessages() mojo/public/cpp/bindings/lib/connector.cc:474:10 (content_browsertests+0x41f024a)
    #28 OnHandleReadyInternal mojo/public/cpp/bindings/lib/connector.cc:375:3 (content_browsertests+0x41f00d5)
    #29 mojo::Connector::OnWatcherHandleReady(unsigned int) mojo/public/cpp/bindings/lib/connector.cc:352 (content_browsertests+0x41f00d5)
    #30 Invoke<mojo::Connector *, unsigned int> base/bind_internal.h:211:12 (content_browsertests+0x41f07ff)
    #31 MakeItSo<void (mojo::Connector::*const &)(unsigned int), mojo::Connector *, unsigned int> base/bind_internal.h:294 (content_browsertests+0x41f07ff)
    #32 RunImpl<void (mojo::Connector::*const &)(unsigned int), const std::__1::tuple<base::internal::UnretainedWrapper<mojo::Connector> > &, 0> base/bind_internal.h:368 (content_browsertests+0x41f07ff)
    #33 base::internal::Invoker<base::internal::BindState<void (mojo::Connector::*)(unsigned int), base::internal::UnretainedWrapper<mojo::Connector> >, void (unsigned int)>::Run(base::internal::BindStateBase*, unsigned int) base/bind_internal.h:350 (content_browsertests+0x41f07ff)
    #34 Run base/callback.h:94:12 (content_browsertests+0x26c9d32)
...
    #58 base::(anonymous namespace)::ThreadFunc(void*) base/threading/platform_thread_posix.cc:75:13 (content_browsertests+0x45e9dfd)

  Mutex M2515 previously acquired by the same thread here:
    #0 pthread_mutex_lock /b/build/slave/linux_upload_clang/build/src/third_party/llvm/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:3801:3 (content_browsertests+0x1645d2e)
    #1 base::internal::LockImpl::Lock() base/synchronization/lock_impl_posix.cc:73:12 (content_browsertests+0x45c635d)
    #2 Acquire base/synchronization/lock.h:26:26 (content_browsertests+0x3587b04)
    #3 AutoLock base/synchronization/lock.h:115 (content_browsertests+0x3587b04)
    #4 blink::scheduler::internal::TaskQueueImpl::PostImmediateTaskImpl(blink::scheduler::TaskQueue::PostedTask) third_party/WebKit/Source/platform/scheduler/base/task_queue_impl.cc:183 (content_browsertests+0x3587b04)
    #5 blink::scheduler::internal::TaskQueueImpl::PostDelayedTask(blink::scheduler::TaskQueue::PostedTask) third_party/WebKit/Source/platform/scheduler/base/task_queue_impl.cc:174:12 (content_browsertests+0x3587a4f)
    #6 blink::scheduler::TaskQueue::PostDelayedTask(base::Location const&, base::OnceCallback<void ()>, base::TimeDelta) third_party/WebKit/Source/platform/scheduler/base/task_queue.cc:75:17 (content_browsertests+0x35863f3)
    #7 base::TaskRunner::PostTask(base::Location const&, base::OnceCallback<void ()>) base/task_runner.cc:44:10 (content_browsertests+0x45ccc2a)
    #8 service_manager::CallbackBinder<content::mojom::ChildControl>::BindInterface(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>) services/service_manager/public/cpp/interface_binder.h:58:21 (content_browsertests+0x6335b08)
    #9 service_manager::BinderRegistryWithArgs<>::BindInterface(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>) services/service_manager/public/cpp/binder_registry.h:86:19 (content_browsertests+0x1d629df)
    #10 TryBindInterface services/service_manager/public/cpp/binder_registry.h:115:7 (content_browsertests+0x1f2c330)
    #11 content::SimpleConnectionFilter::OnBindInterface(service_manager::BindSourceInfo const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>*, service_manager::Connector*) content/public/common/simple_connection_filter.cc:20 (content_browsertests+0x1f2c330)
    #12 content::ServiceManagerConnectionImpl::IOThreadContext::OnBindInterface(service_manager::BindSourceInfo const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>) content/common/service_manager/service_manager_connection_impl.cc:265:23 (content_browsertests+0x24636a6)
    #13 service_manager::ForwardingService::OnBindInterface(service_manager::BindSourceInfo const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>) services/service_manager/public/cpp/service.cc:48:12 (content_browsertests+0x4231b55)
    #14 service_manager::ServiceContext::OnBindInterface(service_manager::BindSourceInfo const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, mojo::ScopedHandleBase<mojo::MessagePipeHandle>, base::OnceCallback<void ()>) services/service_manager/public/cpp/service_context.cc:143:13 (content_browsertests+0x4232c39)
    #15 service_manager::mojom::ServiceStubDispatch::AcceptWithResponder(service_manager::mojom::Service*, mojo::Message*, std::__1::unique_ptr<mojo::MessageReceiverWithStatus, std::__1::default_delete<mojo::MessageReceiverWithStatus> >) out/Release/gen/services/service_manager/public/interfaces/service.mojom.cc:524:13 (content_browsertests+0x4e0d778)
    #16 service_manager::mojom::ServiceStub<mojo::RawPtrImplRefTraits<service_manager::mojom::Service> >::AcceptWithResponder(mojo::Message*, std::__1::unique_ptr<mojo::MessageReceiverWithStatus, std::__1::default_delete<mojo::MessageReceiverWithStatus> >) out/Release/gen/services/service_manager/public/interfaces/service.mojom.h:173:12 (content_browsertests+0x4233991)
    #17 mojo::InterfaceEndpointClient::HandleValidatedMessage(mojo::Message*) mojo/public/cpp/bindings/lib/interface_endpoint_client.cc:394:34 (content_browsertests+0x41f1533)
    #18 mojo::InterfaceEndpointClient::HandleIncomingMessageThunk::Accept(mojo::Message*) mojo/public/cpp/bindings/lib/interface_endpoint_client.cc:133:18 (content_browsertests+0x41f125a)
    #19 mojo::FilterChain::Accept(mojo::Message*) mojo/public/cpp/bindings/lib/filter_chain.cc:40:17 (content_browsertests+0x41f0c7d)
    #20 mojo::InterfaceEndpointClient::HandleIncomingMessage(mojo::Message*) mojo/public/cpp/bindings/lib/interface_endpoint_client.cc:306:19 (content_browsertests+0x41f2854)
    #21 mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::internal::MultiplexRouter::MessageWrapper*, mojo::internal::MultiplexRouter::ClientCallBehavior, base::SequencedTaskRunner*) mojo/public/cpp/bindings/lib/multiplex_router.cc:880:42 (content_browsertests+0x41ff019)
    #22 mojo::internal::MultiplexRouter::Accept(mojo::Message*) mojo/public/cpp/bindings/lib/multiplex_router.cc:604:38 (content_browsertests+0x41fe2d7)
    #23 mojo::FilterChain::Accept(mojo::Message*) mojo/public/cpp/bindings/lib/filter_chain.cc:40:17 (content_browsertests+0x41f0c7d)
    #24 mojo::Connector::ReadSingleMessage(unsigned int*) mojo/public/cpp/bindings/lib/connector.cc:445:51 (content_browsertests+0x41ef7a5)
    #25 mojo::Connector::ReadAllAvailableMessages() mojo/public/cpp/bindings/lib/connector.cc:474:10 (content_browsertests+0x41f024a)
    #26 OnHandleReadyInternal mojo/public/cpp/bindings/lib/connector.cc:375:3 (content_browsertests+0x41f00d5)
    #27 mojo::Connector::OnWatcherHandleReady(unsigned int) mojo/public/cpp/bindings/lib/connector.cc:352 (content_browsertests+0x41f00d5)
    #28 Invoke<mojo::Connector *, unsigned int> base/bind_internal.h:211:12 (content_browsertests+0x41f07ff)
    #29 MakeItSo<void (mojo::Connector::*const &)(unsigned int), mojo::Connector *, unsigned int> base/bind_internal.h:294 (content_browsertests+0x41f07ff)
    #30 RunImpl<void (mojo::Connector::*const &)(unsigned int), const std::__1::tuple<base::internal::UnretainedWrapper<mojo::Connector> > &, 0> base/bind_internal.h:368 (content_browsertests+0x41f07ff)
    #31 base::internal::Invoker<base::internal::BindState<void (mojo::Connector::*)(unsigned int), base::internal::UnretainedWrapper<mojo::Connector> >, void (unsigned int)>::Run(base::internal::BindStateBase*, unsigned int) base/bind_internal.h:350 (content_browsertests+0x41f07ff)
    #32 Run base/callback.h:94:12 (content_browsertests+0x26c9d32)
...
    #56 base::(anonymous namespace)::ThreadFunc(void*) base/threading/platform_thread_posix.cc:75:13 (content_browsertests+0x45e9dfd)

  Mutex M2414 acquired here while holding mutex M2514 in main thread:
    #0 pthread_mutex_lock /b/build/slave/linux_upload_clang/build/src/third_party/llvm/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:3801:3 (content_browsertests+0x1645d2e)
    #1 base::internal::LockImpl::Lock() base/synchronization/lock_impl_posix.cc:73:12 (content_browsertests+0x45c635d)
    #2 Acquire base/synchronization/lock.h:26:26 (content_browsertests+0x4620cf6)
    #3 AutoLock base/synchronization/lock.h:115 (content_browsertests+0x4620cf6)
    #4 base::trace_event::TraceLog::ThreadLocalEventBuffer::AddTraceEvent(base::trace_event::TraceEventHandle*) base/trace_event/trace_log.cc:278 (content_browsertests+0x4620cf6)
    #5 base::trace_event::TraceLog::AddTraceEventWithThreadIdAndTimestamp(char, unsigned char const*, char const*, char const*, unsigned long long, unsigned long long, int, base::TimeTicks const&, int, char const* const*, unsigned char const*, unsigned long long const*, std::__1::unique_ptr<base::trace_event::ConvertableToTraceFormat, std::__1::default_delete<base::trace_event::ConvertableToTraceFormat> >*, unsigned int) base/trace_event/trace_log.cc:1262:48 (content_browsertests+0x46261f7)
    #6 AddTraceEventWithThreadIdAndTimestamp<double> base/trace_event/trace_event.h:905:10 (content_browsertests+0x3585c13)
    #7 AddTraceEvent<double> base/trace_event/trace_event.h:923 (content_browsertests+0x3585c13)
    #8 blink::scheduler::RealTimeDomain::DelayTillNextTask(blink::scheduler::LazyNow*) third_party/WebKit/Source/platform/scheduler/base/real_time_domain.cc:55 (content_browsertests+0x3585c13)
    #9 blink::scheduler::TaskQueueManager::ComputeDelayTillNextTaskLocked(blink::scheduler::LazyNow*) third_party/WebKit/Source/platform/scheduler/base/task_queue_manager.cc:442:22 (content_browsertests+0x3592734)
    #10 blink::scheduler::TaskQueueManager::DoWork(blink::scheduler::internal::Sequence::WorkType) third_party/WebKit/Source/platform/scheduler/base/task_queue_manager.cc:352:9 (content_browsertests+0x3591985)
    #11 Invoke<const base::WeakPtr<blink::scheduler::TaskQueueManager> &, const blink::scheduler::internal::Sequence::WorkType &> base/bind_internal.h:211:12 (content_browsertests+0x3596e71)
    #12 MakeItSo<void (blink::scheduler::TaskQueueManager::*const &)(blink::scheduler::internal::Sequence::WorkType), const base::WeakPtr<blink::scheduler::TaskQueueManager> &, const blink::scheduler::internal::Sequence::WorkType &> base/bind_internal.h:314 (content_browsertests+0x3596e71)
    #13 RunImpl<void (blink::scheduler::TaskQueueManager::*const &)(blink::scheduler::internal::Sequence::WorkType), const std::__1::tuple<base::WeakPtr<blink::scheduler::TaskQueueManager>, blink::scheduler::internal::Sequence::WorkType> &, 0, 1> base/bind_internal.h:368 (content_browsertests+0x3596e71)
    #14 base::internal::Invoker<base::internal::BindState<void (blink::scheduler::TaskQueueManager::*)(blink::scheduler::internal::Sequence::WorkType), base::WeakPtr<blink::scheduler::TaskQueueManager>, blink::scheduler::internal::Sequence::WorkType>, void ()>::Run(base::internal::BindStateBase*) base/bind_internal.h:350 (content_browsertests+0x3596e71)
    #15 Run base/callback.h:65:12 (content_browsertests+0x454c246)
...
    #40 main content/test/content_test_launcher.cc:138:10 (content_browsertests+0x40a805d)

  Mutex M2514 previously acquired by the same thread here:
    #0 pthread_mutex_lock /b/build/slave/linux_upload_clang/build/src/third_party/llvm/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:3801:3 (content_browsertests+0x1645d2e)
    #1 base::internal::LockImpl::Lock() base/synchronization/lock_impl_posix.cc:73:12 (content_browsertests+0x45c635d)
    #2 Acquire base/synchronization/lock.h:26:26 (content_browsertests+0x3591972)
    #3 MoveableAutoLock third_party/WebKit/Source/platform/scheduler/base/moveable_auto_lock.h:16 (content_browsertests+0x3591972)
    #4 blink::scheduler::TaskQueueManager::DoWork(blink::scheduler::internal::Sequence::WorkType) third_party/WebKit/Source/platform/scheduler/base/task_queue_manager.cc:350 (content_browsertests+0x3591972)
    #5 Invoke<const base::WeakPtr<blink::scheduler::TaskQueueManager> &, const blink::scheduler::internal::Sequence::WorkType &> base/bind_internal.h:211:12 (content_browsertests+0x3596e71)
    #6 MakeItSo<void (blink::scheduler::TaskQueueManager::*const &)(blink::scheduler::internal::Sequence::WorkType), const base::WeakPtr<blink::scheduler::TaskQueueManager> &, const blink::scheduler::internal::Sequence::WorkType &> base/bind_internal.h:314 (content_browsertests+0x3596e71)
    #7 RunImpl<void (blink::scheduler::TaskQueueManager::*const &)(blink::scheduler::internal::Sequence::WorkType), const std::__1::tuple<base::WeakPtr<blink::scheduler::TaskQueueManager>, blink::scheduler::internal::Sequence::WorkType> &, 0, 1> base/bind_internal.h:368 (content_browsertests+0x3596e71)
    #8 base::internal::Invoker<base::internal::BindState<void (blink::scheduler::TaskQueueManager::*)(blink::scheduler::internal::Sequence::WorkType), base::WeakPtr<blink::scheduler::TaskQueueManager>, blink::scheduler::internal::Sequence::WorkType>, void ()>::Run(base::internal::BindStateBase*) base/bind_internal.h:350 (content_browsertests+0x3596e71)
    #9 Run base/callback.h:65:12 (content_browsertests+0x454c246)
...
    #34 main content/test/content_test_launcher.cc:138:10 (content_browsertests+0x40a805d)

  Mutex M2515 acquired here while holding mutex M2414 in main thread:
    #0 pthread_mutex_lock /b/build/slave/linux_upload_clang/build/src/third_party/llvm/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:3801:3 (content_browsertests+0x1645d2e)
    #1 base::internal::LockImpl::Lock() base/synchronization/lock_impl_posix.cc:73:12 (content_browsertests+0x45c635d)
    #2 Acquire base/synchronization/lock.h:26:26 (content_browsertests+0x3587b04)
    #3 AutoLock base/synchronization/lock.h:115 (content_browsertests+0x3587b04)
    #4 blink::scheduler::internal::TaskQueueImpl::PostImmediateTaskImpl(blink::scheduler::TaskQueue::PostedTask) third_party/WebKit/Source/platform/scheduler/base/task_queue_impl.cc:183 (content_browsertests+0x3587b04)
    #5 blink::scheduler::internal::TaskQueueImpl::PostDelayedTask(blink::scheduler::TaskQueue::PostedTask) third_party/WebKit/Source/platform/scheduler/base/task_queue_impl.cc:174:12 (content_browsertests+0x3587a4f)
    #6 blink::scheduler::TaskQueue::PostDelayedTask(base::Location const&, base::OnceCallback<void ()>, base::TimeDelta) third_party/WebKit/Source/platform/scheduler/base/task_queue.cc:75:17 (content_browsertests+0x35863f3)
    #7 base::TaskRunner::PostTask(base::Location const&, base::OnceCallback<void ()>) base/task_runner.cc:44:10 (content_browsertests+0x45ccc2a)
    #8 base::trace_event::TraceLog::FlushCurrentThread(int, bool) base/trace_event/trace_log.cc:979:23 (content_browsertests+0x462519f)
    #9 Invoke<base::trace_event::TraceLog *, int, bool> base/bind_internal.h:211:12 (content_browsertests+0x462b24e)
    #10 MakeItSo<void (base::trace_event::TraceLog::*)(int, bool), base::trace_event::TraceLog *, int, bool> base/bind_internal.h:294 (content_browsertests+0x462b24e)
    #11 RunImpl<void (base::trace_event::TraceLog::*)(int, bool), std::__1::tuple<base::internal::UnretainedWrapper<base::trace_event::TraceLog>, int, bool>, 0, 1, 2> base/bind_internal.h:368 (content_browsertests+0x462b24e)
    #12 base::internal::Invoker<base::internal::BindState<void (base::trace_event::TraceLog::*)(int, bool), base::internal::UnretainedWrapper<base::trace_event::TraceLog>, int, bool>, void ()>::RunOnce(base::internal::BindStateBase*) base/bind_internal.h:336 (content_browsertests+0x462b24e)
    #13 Run base/callback.h:65:12 (content_browsertests+0x454c246)
...
    #46 main content/test/content_test_launcher.cc:138:10 (content_browsertests+0x40a805d)

  Mutex M2414 previously acquired by the same thread here:
    #0 pthread_mutex_lock /b/build/slave/linux_upload_clang/build/src/third_party/llvm/compiler-rt/lib/tsan/../sanitizer_common/sanitizer_common_interceptors.inc:3801:3 (content_browsertests+0x1645d2e)
    #1 base::internal::LockImpl::Lock() base/synchronization/lock_impl_posix.cc:73:12 (content_browsertests+0x45c635d)
    #2 Acquire base/synchronization/lock.h:26:26 (content_browsertests+0x46250b6)
    #3 AutoLock base/synchronization/lock.h:115 (content_browsertests+0x46250b6)
    #4 base::trace_event::TraceLog::FlushCurrentThread(int, bool) base/trace_event/trace_log.cc:974 (content_browsertests+0x46250b6)
    #5 Invoke<base::trace_event::TraceLog *, int, bool> base/bind_internal.h:211:12 (content_browsertests+0x462b24e)
    #6 MakeItSo<void (base::trace_event::TraceLog::*)(int, bool), base::trace_event::TraceLog *, int, bool> base/bind_internal.h:294 (content_browsertests+0x462b24e)
    #7 RunImpl<void (base::trace_event::TraceLog::*)(int, bool), std::__1::tuple<base::internal::UnretainedWrapper<base::trace_event::TraceLog>, int, bool>, 0, 1, 2> base/bind_internal.h:368 (content_browsertests+0x462b24e)
    #8 base::internal::Invoker<base::internal::BindState<void (base::trace_event::TraceLog::*)(int, bool), base::internal::UnretainedWrapper<base::trace_event::TraceLog>, int, bool>, void ()>::RunOnce(base::internal::BindStateBase*) base/bind_internal.h:336 (content_browsertests+0x462b24e)
    #9 Run base/callback.h:65:12 (content_browsertests+0x454c246)
...
    #42 main content/test/content_test_launcher.cc:138:10 (content_browsertests+0x40a805d)

  Thread T6 'Chrome_ChildIOThread' (tid=15486, running) created by main thread at:
    #0 pthread_create /b/build/slave/linux_upload_clang/build/src/third_party/llvm/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:921:3 (content_browsertests+0x162b433)
    #1 base::(anonymous namespace)::CreateThread(unsigned long, bool, base::PlatformThread::Delegate*, base::PlatformThreadHandle*, base::ThreadPriority) base/threading/platform_thread_posix.cc:114:13 (content_browsertests+0x45e9987)
    #2 base::PlatformThread::CreateWithPriority(unsigned long, base::PlatformThread::Delegate*, base::PlatformThreadHandle*, base::ThreadPriority) base/threading/platform_thread_posix.cc:199:10 (content_browsertests+0x45e9885)
    #3 base::Thread::StartWithOptions(base::Thread::Options const&) base/threading/thread.cc:112:15 (content_browsertests+0x45f24c7)
...
    #16 main content/test/content_test_launcher.cc:138:10 (content_browsertests+0x40a805d)

SUMMARY: ThreadSanitizer: lock-order-inversion (potential deadlock) base/synchronization/lock_impl_posix.cc:73:12 in base::internal::LockImpl::Lock()
==================

Alexander, could you please take a look?

 
Status: Started (was: Assigned)
Thanks for reporting this!

This is a problem when a) scheduling does some tracing when posting a task, grabbing tracing controller lock b) tracing posts a task to the scheduler while holding a tracing lock.

To fix this I'll change tracing code to post a task outside the lock.
Project Member

Comment 2 by bugdroid1@chromium.org, Jan 5 2018

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

commit b7e650ffa1ce55ef38aa040c8a51a6045020d091
Author: Alexander Timin <altimin@chromium.org>
Date: Fri Jan 05 17:30:56 2018

tracing: Avoid scheduler/tracing deadlock.

Scheduler grabs a tracing lock in TRACE_EVENT macros.
Tracing grabs a scheduling lock inside TaskRunner::PostTask.
Break the deadlock by posting a task outside tracing lock.

R=primiano@chromium.org
BUG= 797966 

Change-Id: I20039a2b78df3c962d8ca44a65efb0cebdc676d8
Reviewed-on: https://chromium-review.googlesource.com/848898
Reviewed-by: Primiano Tucci <primiano@chromium.org>
Commit-Queue: Alexander Timin <altimin@chromium.org>
Cr-Commit-Position: refs/heads/master@{#527310}
[modify] https://crrev.com/b7e650ffa1ce55ef38aa040c8a51a6045020d091/base/trace_event/trace_log.cc

Status: Fixed (was: Started)
This should be fixed now. Can I reproduce it somehow to verify that? Or could you confirm that it is indeed the case?

And thanks for finding this deadlock!
According to newer build logs (https://chromium-swarm.appspot.com/task?id=3aeefb087647b810&refresh=10&show_raw=1) the bug has been fixed (there're no TSan reports in TracingControllerTest.EnableAndStopTracingWithCompression)
Thanks!
Status: Verified (was: Fixed)
Thanks for confirming!

Sign in to add a comment