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

Issue 665945 link

Starred by 2 users
Status: Fixed
Owner:
fdoray@chromium.org
Closed: Nov 2016
Cc:
█ roc...@chromium.org
thestig@chromium.org
gab@chromium.org
█ euge...@chromium.org
█ glider@chromium.org
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 3
Type: Bug



Sign in to add a comment

Data race between logging initialization and assertion in unit tests

Project Member Reported by fdoray@chromium.org, Nov 16 2016 
content_unittests fail with the following error (see https://codereview.chromium.org/2502973002/):

WARNING: ThreadSanitizer: data race (pid=7917)
  Read of size 4 at 0x00000a575df0 by thread T1:
    #0 logging::ShouldCreateLogMessage(int) base/logging.cc:412:10 (content_unittests+0x0000042bbb87)
    #1 operator-> base/memory/ref_counted.h:319:5 (content_unittests+0x0000042c7923)
    #2 base::MessageLoop::BindToCurrentThread() base/message_loop/message_loop.cc:343 (content_unittests+0x0000042c7923)
    #3 base::Thread::ThreadMain() base/threading/thread.cc:299:18 (content_unittests+0x0000043299d0)
    #4 base::(anonymous namespace)::ThreadFunc(void*) base/threading/platform_thread_posix.cc:71:13 (content_unittests+0x00000431fea8)

  Previous write of size 4 at 0x00000a575df0 by main thread:
    #0 logging::BaseInitLoggingImpl_built_with_NDEBUG(logging::LoggingSettings const&) base/logging.cc:373:25 (content_unittests+0x0000042bb834)
    #1 InitLogging base/logging.h:232:10 (content_unittests+0x00000361e24a)
    #2 base::TestSuite::Initialize() base/test/test_suite.cc:331 (content_unittests+0x00000361e24a)
    #3 content::ContentTestSuiteBase::Initialize() content/public/test/content_test_suite_base.cc:61:20 (content_unittests+0x00000360e549)
    #4 content::ContentTestSuite::Initialize() content/test/content_test_suite.cc:78:25 (content_unittests+0x0000035dc0d0)
    #5 base::TestSuite::Run() base/test/test_suite.cc:234:3 (content_unittests+0x00000361dc07)
    #6 content::UnitTestTestSuite::Run() content/public/test/unittest_test_suite.cc:45:23 (content_unittests+0x0000035db351)
    #7 Invoke<content::UnitTestTestSuite *> base/bind_internal.h:214:12 (content_unittests+0x000001761ae5)
    #8 MakeItSo<int (content::UnitTestTestSuite::*const &)(), content::UnitTestTestSuite *> base/bind_internal.h:285 (content_unittests+0x000001761ae5)
    #9 RunImpl<int (content::UnitTestTestSuite::*const &)(), const std::__1::tuple<base::internal::UnretainedWrapper<content::UnitTestTestSuite> > &, 0> base/bind_internal.h:361 (content_unittests+0x000001761ae5)
    #10 base::internal::Invoker<base::internal::BindState<int (content::UnitTestTestSuite::*)(), base::internal::UnretainedWrapper<content::UnitTestTestSuite> >, int ()>::Run(base::internal::BindStateBase*) base/bind_internal.h:339 (content_unittests+0x000001761ae5)
    #11 Run base/callback.h:64:12 (content_unittests+0x00000363a8a3)
    #12 base::(anonymous namespace)::LaunchUnitTestsInternal(base::Callback<int (), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&, int, int, bool, base::Callback<void (), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&) base/test/launcher/unit_test_launcher.cc:211 (content_unittests+0x00000363a8a3)
    #13 base::LaunchUnitTests(int, char**, base::Callback<int (), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&) base/test/launcher/unit_test_launcher.cc:453:10 (content_unittests+0x00000363a6ca)
    #14 main content/test/run_all_unittests.cc:22:10 (content_unittests+0x000001761a13)

  Location is global 'logging::(anonymous namespace)::g_logging_destination' of size 4 at 0x00000a575df0 (content_unittests+0x00000a575df0)

  Thread T1 'test_io_thread' (tid=7942, running) created by main thread at:
    #0 pthread_create <null> (content_unittests+0x000000525585)
    #1 base::(anonymous namespace)::CreateThread(unsigned long, bool, base::PlatformThread::Delegate*, base::PlatformThreadHandle*, base::ThreadPriority) base/threading/platform_thread_posix.cc:110:13 (content_unittests+0x00000431fa35)
    #2 base::PlatformThread::CreateWithPriority(unsigned long, base::PlatformThread::Delegate*, base::PlatformThreadHandle*, base::ThreadPriority) base/threading/platform_thread_posix.cc:191:10 (content_unittests+0x00000431f8e5)
    #3 base::Thread::StartWithOptions(base::Thread::Options const&) base/threading/thread.cc:112:15 (content_unittests+0x000004328ba5)
    #4 base::TestIOThread::Start() base/test/test_io_thread.cc:30:3 (content_unittests+0x000003619a7a)
    #5 base::TestIOThread::TestIOThread(base::TestIOThread::Mode) base/test/test_io_thread.cc:15:7 (content_unittests+0x00000361996e)
    #6 main content/test/run_all_unittests.cc:17:22 (content_unittests+0x00000176193a)

Comment 1 by gab@chromium.org, Nov 16 2016 

@TSAN owners: is there no longer a Memory sheriff? Are Chromium sheriffs aware that they're supposed to monitor this one (I sure wasn't as an occasional Chromium sheriff..)

Comment 2 by dcheng@chromium.org, Nov 16 2016

Cc: roc...@chromium.org
It seems like there's two different errors here.

One is 663557 (mojo lock inversion), which should be fixed. Not sure about the other one though.

Comment 3 by roc...@chromium.org, Nov 16 2016 

Actually this might be a different inversion than the one that was fixed. FWIW in both cases there is no potential for actual deadlock, but I'd still rather try to fix this one rather than suppress it if possible.

Not sure about the logging data race.

Comment 4 by fdoray@chromium.org, Nov 16 2016 

I'm taking care of the logging data race https://codereview.chromium.org/2494133002/

Haven't investigated the mojo lock inversion.

Comment 5 by roc...@chromium.org, Nov 16 2016 

I filed a separate  bug 665996  for the mojo thing and will take care of it.

Comment 6 by fdoray@chromium.org, Nov 17 2016

Description: Show this description

Comment 7 by fdoray@chromium.org, Nov 17 2016

Cc: -dcheng@chromium.org thestig@chromium.org
Summary: Data race between logging initialization and assertion in unit tests (was: Linux TSan Tests bot is broken)
Project Member

Comment 8 by bugdroid1@chromium.org, Nov 17 2016 

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

commit 4394a610dc161262d1ec2913d55e29727a79d25f
Author: fdoray <fdoray@chromium.org>
Date: Thu Nov 17 14:41:21 2016

Fix a data race in multiple unit tests processes.

There is a race between TestSuite::Initialize() initializing logging
and the "test_io_thread" using assert(). This CL fixes this race by
initializing logging in the constructor of TestSuite, before any
thread is created.

See failing unit tests in this CL:
https://codereview.chromium.org/2502973002/

BUG= 665945 

Review-Url: https://codereview.chromium.org/2494133002
Cr-Commit-Position: refs/heads/master@{#432869}

[modify] https://crrev.com/4394a610dc161262d1ec2913d55e29727a79d25f/base/test/test_suite.cc
[modify] https://crrev.com/4394a610dc161262d1ec2913d55e29727a79d25f/base/test/test_support_android.cc
[modify] https://crrev.com/4394a610dc161262d1ec2913d55e29727a79d25f/base/test/test_support_android.h
[modify] https://crrev.com/4394a610dc161262d1ec2913d55e29727a79d25f/chrome/browser/sync_file_system/logger_unittest.cc

Comment 9 by fdoray@chromium.org, Nov 18 2016

Status: Fixed (was: Started)

Comment 10 by glider@chromium.org, Nov 22 2016 

#1: there are memory sheriffs, but bugs reported in content_browsertests don't show up on the waterfall due to issue 368525.
►

Sign in to add a comment