Data race accessing logging.cc::g_min_log_level |
||
Issue descriptionThis race is caught by every test that overrides InProcessBrowserTest::SetUp() to do something before if that something does logging (e.g. virtually all). This race is also real in the product. If any thread (including main thread) calls SetMinLogLevel() at any point, it races with any log statement trying to GetMinLogLevel(). As usual, there is no such thing as benign data race: https://software.intel.com/en-us/blogs/2013/01/06/benign-data-races-what-could-possibly-go-wrong This is a prerequisite to enabling TSAN for browser_tests. Log: WARNING: ThreadSanitizer: data race (pid=9471) Write of size 4 at 0x0000106c47d0 by main thread: #0 logging::SetMinLogLevel(int) base/logging.cc:412:19 (browser_tests+0x4256c1b) #1 logging::InitChromeLogging(base::CommandLine const&, logging::OldFileDeletionState) chrome/common/logging_chrome.cc:325:7 (browser_tests+0x5e28b4f) #2 InitLogging chrome/app/chrome_main_delegate.cc:487:3 (browser_tests+0x5e0cb00) #3 ChromeMainDelegate::PreSandboxStartup() chrome/app/chrome_main_delegate.cc:837 (browser_tests+0x5e0cb00) #4 content::ContentMainRunnerImpl::Initialize(content::ContentMainParams const&) content/app/content_main_runner.cc:638:18 (browser_tests+0x41f3a05) #5 content::ContentServiceManagerMainDelegate::Initialize(service_manager::MainDelegate::InitializeParams const&) content/app/content_service_manager_main_delegate.cc:37:32 (browser_tests+0x41f15a4) #6 service_manager::Main(service_manager::MainParams const&) services/service_manager/embedder/main.cc:426:29 (browser_tests+0x7035226) #7 content::ContentMain(content::ContentMainParams const&) content/app/content_main.cc:19:10 (browser_tests+0x41f1fcb) #8 content::BrowserTestBase::SetUp() content/public/test/browser_test_base.cc:271:3 (browser_tests+0x4d46146) #9 InProcessBrowserTest::SetUp() chrome/test/base/in_process_browser_test.cc:271:20 (browser_tests+0x43939d0) #10 HistoryBrowserTest::SetUp() chrome/browser/history/history_browsertest.cc:56:27 (browser_tests+0x8bae07) (...) Previous read of size 4 at 0x0000106c47d0 by thread T1: #0 GetMinLogLevel base/logging.cc:416:10 (browser_tests+0x4256ddc) #1 GetVlogVerbosity base/logging.cc:431 (browser_tests+0x4256ddc) #2 logging::GetVlogLevelHelper(char const*, unsigned long) base/logging.cc:441 (browser_tests+0x4256ddc) #3 GetVlogLevel<35> base/logging.h:261:10 (browser_tests+0x51854a0) #4 net::MapSystemError(int) net/base/net_errors_posix.cc:18 (browser_tests+0x51854a0) #5 MapAcceptError net/socket/socket_posix.cc:38:14 (browser_tests+0x527cd91) #6 net::SocketPosix::DoAccept(std::__1::unique_ptr<net::SocketPosix, std::__1::default_delete<net::SocketPosix> >*) net/socket/socket_posix.cc:422 (browser_tests+0x527cd91) #7 net::SocketPosix::Accept(std::__1::unique_ptr<net::SocketPosix, std::__1::default_delete<net::SocketPosix> >*, base::Callback<void (int), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&) net/socket/socket_posix.cc:166:12 (browser_tests+0x527cb8a) #8 net::TCPSocketPosix::Accept(std::__1::unique_ptr<net::TCPSocketPosix, std::__1::default_delete<net::TCPSocketPosix> >*, net::IPEndPoint*, base::Callback<void (int), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&) net/socket/tcp_socket_posix.cc:231:21 (browser_tests+0x50d6d57) #9 net::TCPServerSocket::Accept(std::__1::unique_ptr<net::StreamSocket, std::__1::default_delete<net::StreamSocket> >*, base::Callback<void (int), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&) net/socket/tcp_server_socket.cc:73:24 (browser_tests+0x50d5af1) #10 net::test_server::EmbeddedTestServer::DoAcceptLoop() net/test/embedded_test_server/embedded_test_server.cc:347:26 (browser_tests+0x5355961) (...) Location is global 'logging::(anonymous namespace)::g_min_log_level' of size 4 at 0x0000106c47d0 (browser_tests+0x0000106c47d0) Thread T1 'EmbeddedTestServer IO Thread' (tid=9513, running) created by main thread at: #0 pthread_create <null> (browser_tests+0x58d6b3) #1 base::(anonymous namespace)::CreateThread(unsigned long, bool, base::PlatformThread::Delegate*, base::PlatformThreadHandle*, base::ThreadPriority) base/threading/platform_thread_posix.cc:110:13 (browser_tests+0x42ee166) #2 base::PlatformThread::CreateWithPriority(unsigned long, base::PlatformThread::Delegate*, base::PlatformThreadHandle*, base::ThreadPriority) base/threading/platform_thread_posix.cc:193:10 (browser_tests+0x42ee025) #3 base::Thread::StartWithOptions(base::Thread::Options const&) base/threading/thread.cc:112:15 (browser_tests+0x42f9b53) #4 net::test_server::EmbeddedTestServer::StartAcceptingConnections() net/test/embedded_test_server/embedded_test_server.cc:172:3 (browser_tests+0x5354b3d) #5 net::test_server::EmbeddedTestServer::Start() net/test/embedded_test_server/embedded_test_server.cc:89:3 (browser_tests+0x5354285) #6 HistoryBrowserTest::SetUp() chrome/browser/history/history_browsertest.cc:55:5 (browser_tests+0x8badf0) (...) SUMMARY: ThreadSanitizer: data race base/logging.cc:412:19 in logging::SetMinLogLevel(int)
,
Jul 26 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/60d3f7a4275923fb934550908dd3a9999061c1c1 commit 60d3f7a4275923fb934550908dd3a9999061c1c1 Author: Gabriel Charette <gab@chromium.org> Date: Wed Jul 26 23:34:56 2017 Do not explicitly set kLoggingLevel in browser_tests. The value specified was the same as the default value in logging.cc but passing the flag explicitly resulted in a write to logging.cc::g_min_log_level which would race with reads in tests that kick off async tasks prior to kicking off their browser. This CL is attempt #2 at this after dropping https://chromium-review.googlesource.com/c/585853/ Bug: 749066 , 368525 Change-Id: I83a55241300e5e40af15c6ca702551b579dacbfd Reviewed-on: https://chromium-review.googlesource.com/587418 Reviewed-by: danakj <danakj@chromium.org> Reviewed-by: Scott Violet <sky@chromium.org> Commit-Queue: Gabriel Charette <gab@chromium.org> Cr-Commit-Position: refs/heads/master@{#489799} [modify] https://crrev.com/60d3f7a4275923fb934550908dd3a9999061c1c1/chrome/test/base/test_launcher_utils.cc
,
Jul 27 2017
|
||
►
Sign in to add a comment |
||
Comment 1 by gab@chromium.org
, Jul 26 2017Status: Started (was: St)