Many unittests "fail" under TSAN without a "failure".. |
|||||
Issue descriptionDec 06 16:11 44cb4ef79a3c5b39ed659a963988035874b546d2 failure #4193 Failed steps failed base_unittests failed content_browsertests failed content_unittests failed events_unittests failed extensions_unittests Dec 06 14:32 acf834a5675c89f8b4c3b44a4dfeed3fb4be4375 failure #4192 Failed steps failed base_unittests failed content_browsertests Up to acf834a5675c89f8b4c3b44a4dfeed3fb4be4375 the bot had a few consistent failures with a TSAN report in base_unittests and content_browsertests (filed other bugs for those). As of 44cb4ef79a3c5b39ed659a963988035874b546d2 many unittests fail all tests with a log indicating that all tests passed with a single warning at the end, e.g.: ArgumentSpecUnitTest.Test (run #1): [ RUN ] ArgumentSpecUnitTest.Test [ OK ] ArgumentSpecUnitTest.Test (94 ms) [ RUN ] ArgumentSpecUnitTest.TypeRefsTest [ OK ] ArgumentSpecUnitTest.TypeRefsTest (70 ms) [----------] 2 tests from ArgumentSpecUnitTest (165 ms total) [----------] 4 tests from EventUnittest [ RUN ] EventUnittest.TestNothing [ OK ] EventUnittest.TestNothing (90 ms) [ RUN ] EventUnittest.AddRemoveTwoListeners [ OK ] EventUnittest.AddRemoveTwoListeners (169 ms) [ RUN ] EventUnittest.EventsThatSupportRulesMustHaveAName [ OK ] EventUnittest.EventsThatSupportRulesMustHaveAName (94 ms) [ RUN ] EventUnittest.NamedEventDispatch [ OK ] EventUnittest.NamedEventDispatch (104 ms) [----------] 4 tests from EventUnittest (458 ms total) [----------] Global test environment tear-down [==========] 10 tests from 3 test cases ran. (2509 ms total) [ PASSED ] 10 tests. ThreadSanitizer: reported 1 warnings Regression range: https://chromium.googlesource.com/chromium/src/+log/acf834a5675c89f8b4c3b44a4dfeed3fb4be4375..44cb4ef79a3c5b39ed659a963988035874b546d2?pretty=fuller&n=10000
,
Dec 9 2016
Crash is on test exit, suspected to be caused by r436745. @fdoray Example log from running locally with: is_component_build = true is_debug = false is_tsan = true ninja -C out/Tsan events_unittests && out/Tsan/events_unittests --gtest_filter=AnimateInput* WARNING: ThreadSanitizer: data race (pid=18758) Write of size 8 at 0x7efca4c27368 by main thread: #0 StatisticsRecorder base/metrics/statistics_recorder.cc:491 (libbase.so+0x0000000fcc4c) #1 New base/lazy_instance.h:69 (libbase.so+0x0000000fa780) #2 New base/lazy_instance.h:98 (libbase.so+0x0000000fa780) #3 Pointer base/lazy_instance.h:163 (libbase.so+0x0000000fa780) #4 Get base/lazy_instance.h:137 (libbase.so+0x0000000fa780) #5 Initialize base/metrics/statistics_recorder.cc:108 (libbase.so+0x0000000fa780) #6 HistogramTester base/test/histogram_tester.cc:19 (events_unittests+0x0000006e74c5) #7 InputHandlerProxyTest ui/events/blink/input_handler_proxy_unittest.cc:351 (events_unittests+0x000000624d69) #8 InputHandlerProxyTest_DidReceiveInputEvent_ForFling_Test ui/events/blink/input_handler_proxy_unittest.cc:2781 (events_unittests+0x00000062d14e) #9 CreateTest testing/gtest/include/gtest/internal/gtest-param-util.h:415 (events_unittests+0x00000062d14e) #10 HandleExceptionsInMethodIfSupported<testing::internal::TestFactoryBase, testing::Test *> testing/gtest/src/gtest.cc:2458 (events_unittests+0x00000071d796) #11 Run testing/gtest/src/gtest.cc:2647 (events_unittests+0x00000071d796) #12 Run testing/gtest/src/gtest.cc:2774 (events_unittests+0x00000071e1a6) #13 RunAllTests testing/gtest/src/gtest.cc:4647 (events_unittests+0x000000729156) #14 HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl, bool> testing/gtest/src/gtest.cc:2458 (events_unittests+0x0000007289e9) #15 Run testing/gtest/src/gtest.cc:4255 (events_unittests+0x0000007289e9) #16 RUN_ALL_TESTS testing/gtest/include/gtest/gtest.h:2237 (events_unittests+0x0000006ea1e9) #17 Run base/test/test_suite.cc:271 (events_unittests+0x0000006ea1e9) #18 Invoke<base::TestSuite *> base/bind_internal.h:214 (events_unittests+0x0000006c7165) #19 MakeItSo<int (base::TestSuite::*const &)(), base::TestSuite *> base/bind_internal.h:285 (events_unittests+0x0000006c7165) #20 RunImpl<int (base::TestSuite::*const &)(), const std::__1::tuple<base::internal::UnretainedWrapper<base::TestSuite> > &, 0> base/bind_internal.h:361 (events_unittests+0x0000006c7165) #21 Run base/bind_internal.h:339 (events_unittests+0x0000006c7165) #22 Run base/callback.h:85 (events_unittests+0x0000006eb893) #23 LaunchUnitTestsInternal base/test/launcher/unit_test_launcher.cc:211 (events_unittests+0x0000006eb893) #24 LaunchUnitTests base/test/launcher/unit_test_launcher.cc:453 (events_unittests+0x0000006eb71a) #25 main mojo/edk/test/run_all_unittests.cc:48 (events_unittests+0x0000006c70a4) Previous read of size 8 at 0x7efca4c27368 by thread T1: #0 ImportGlobalPersistentHistograms base/metrics/statistics_recorder.cc:468 (libbase.so+0x0000000fbebe) #1 FindHistogram base/metrics/statistics_recorder.cc:313 (libbase.so+0x0000000fbebe) #2 Build base/metrics/histogram.cc:149 (libbase.so+0x0000000e587e) #3 FactoryGet base/metrics/histogram.cc:243 (libbase.so+0x0000000e604c) #4 FactoryTimeGet base/metrics/histogram.cc:251 (libbase.so+0x0000000e604c) #5 FactoryTimeGet base/metrics/histogram.cc:269 (libbase.so+0x0000000e604c) #6 ~ScopedHistogramTimer0 base/tracked_objects.cc:907 (libbase.so+0x0000001b0544) #7 GetRetiredOrCreateThreadData base/tracked_objects.cc:935 (libbase.so+0x0000001b0544) #8 tracked_objects::ThreadData::InitializeThreadContext(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) base/tracked_objects.cc:451 (libbase.so+0x0000001b008e) #9 SetName base/threading/platform_thread_linux.cc:111 (libbase.so+0x00000015ee24) #10 ThreadMain base/threading/thread.cc:288 (libbase.so+0x000000169a5d) #11 ThreadFunc base/threading/platform_thread_posix.cc:71 (libbase.so+0x00000015f7dd) Location is global '<null>' at 0x000000000000 (libbase.so+0x000000217368) Thread T1 'test_io_thread' (tid=18764, running) created by main thread at: #0 pthread_create <null> (events_unittests+0x000000468d55) #1 CreateThread base/threading/platform_thread_posix.cc:110 (libbase.so+0x00000015f2d7) #2 base::PlatformThread::CreateWithPriority(unsigned long, base::PlatformThread::Delegate*, base::PlatformThreadHandle*, base::ThreadPriority) base/threading/platform_thread_posix.cc:191 (libbase.so+0x00000015f1d5) #3 StartWithOptions base/threading/thread.cc:112 (libbase.so+0x0000001692a5) #4 base::TestIOThread::Start() base/test/test_io_thread.cc:30 (events_unittests+0x0000006ea09a) #5 TestIOThread base/test/test_io_thread.cc:15 (events_unittests+0x0000006e9f8e) #6 main mojo/edk/test/run_all_unittests.cc:45 (events_unittests+0x0000006c6fd4) SUMMARY: ThreadSanitizer: data race base/metrics/statistics_recorder.cc:491 in StatisticsRecorder
,
Dec 9 2016
,
Dec 9 2016
That CL is only at fault because it happens to attempt to log an histogram before StatisticsRecorder::Initialize was called which is racy. I'll fix it in StatisticsRecorder instead.
,
Dec 12 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/c435080b8ebaca0d833b2c2e261eafa2090f725d commit c435080b8ebaca0d833b2c2e261eafa2090f725d Author: gab <gab@chromium.org> Date: Mon Dec 12 22:36:39 2016 Fix TSAN race in access to StatisticsRecorder::lock_ BUG= 672852 TEST=No more content_unittests, events_unittests, and extensions_unittests failures on linux_chromium_tsan_rel_ng Confirmed @ https://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_tsan_rel_ng/builds/377 Review-Url: https://codereview.chromium.org/2565893002 Cr-Commit-Position: refs/heads/master@{#437932} [modify] https://crrev.com/c435080b8ebaca0d833b2c2e261eafa2090f725d/base/metrics/statistics_recorder.cc [modify] https://crrev.com/c435080b8ebaca0d833b2c2e261eafa2090f725d/base/metrics/statistics_recorder.h
,
Dec 13 2016
Fixed :) : https://build.chromium.org/p/chromium.memory.full/builders/Linux%20TSan%20Tests?numbuilds=200 |
|||||
►
Sign in to add a comment |
|||||
Comment 1 by gab@chromium.org
, Dec 9 2016