Build failure: views_unittests is flakey in Mac ASan 64 Tests (1) Build |
||||
Issue descriptionBuild is broken: views_unittests on Mac-10.9 Revision range: chromium 403003 : 403024 Failing builders: Mac ASan 64 Tests (1): https://build.chromium.org/p/chromium.memory/builders/Mac%20ASan%2064%20Tests%20(1) https://build.chromium.org/p/chromium.memory/builders/Mac%20ASan%2064%20Tests%20%281%29/builds/18203 [ RUN ] TextfieldTest.FocusTraversalTest [ OK ] TextfieldTest.FocusTraversalTest (67 ms) [487/734] TextfieldTest.FocusTraversalTest (67 ms) [ RUN ] TextfieldTest.ContextMenuDisplayTest ================================================================= ==39322==ERROR: AddressSanitizer: heap-use-after-free on address 0x616000043958 at pc 0x000110a6a453 bp 0x7fff50c98b70 sp 0x7fff50c98b68 READ of size 8 at 0x616000043958 thread T0 LLVMSymbolizer: error reading file: No such file or directory #0 0x110a6a452 in Traceback (most recent call last): File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/asan_symbolize.py", line 271, in <module> main() File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/asan_symbolize.py", line 268, in main loop.process_logfile() File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 416, in process_logfile processed = self.process_line(line) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 439, in process_line_posix symbolized_line = self.symbolize_address(addr, binary, offset) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 393, in symbolize_address result = symbolizers[binary].symbolize(addr, binary, offset) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 244, in symbolize result = symbolizer.symbolize(addr, binary, offset) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 216, in symbolize atos_line = self.atos.convert('0x%x' % int(offset, 16)) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 192, in convert self.w.write(line + "\n") IOError: [Errno 5] Input/output error Error: failed to symbolize snippets in JSON: LLVMSymbolizer: error reading file: No such file or directory Traceback (most recent call last): File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/asan_symbolize.py", line 271, in <module> main() File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/asan_symbolize.py", line 264, in main symbolize_snippets_in_json(args.test_summary_json_file, loop) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/asan_symbolize.py", line 227, in symbolize_snippets_in_json test_run_symbolizer.symbolize(test_run) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/asan_symbolize.py", line 199, in symbolize symbolized_snippet = self.symbolize_snippet(original_snippet) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/asan_symbolize.py", line 194, in symbolize_snippet symbolized_lines += self.symbolization_loop.process_line(line) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 439, in process_line_posix symbolized_line = self.symbolize_address(addr, binary, offset) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 393, in symbolize_address result = symbolizers[binary].symbolize(addr, binary, offset) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 244, in symbolize result = symbolizer.symbolize(addr, binary, offset) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 216, in symbolize atos_line = self.atos.convert('0x%x' % int(offset, 16)) File "/b/swarm_slave/work/isolated/isolated_runo5G9SV/tools/valgrind/asan/third_party/asan_symbolize.py", line 192, in convert self.w.write(line + "\n") IOError: [Errno 5] Input/output error
,
Jun 30 2016
This is similar to another flaky test which was disabled recently - http://crbug.com/624555 . Over to Trent who has a patch for it.
,
Jun 30 2016
I don't think it's related to RunMenuAndCancel. But I've managed to get a UAF in views_unittests in a local ASAN build:
[ RUN ] TextfieldTest.HitOutsideTextAreaInRTLTest
=================================================================
==73909==ERROR: AddressSanitizer: heap-use-after-free on address 0x6160000faf58 at pc 0x000109e841c3 bp 0x7fff5674a4b0 sp 0x7fff5674a4a8
READ of size 8 at 0x6160000faf58 thread T0
#0 0x109e841c2 in cc::TileTaskManagerImpl::Shutdown() tile_task_manager.cc:52
#1 0x109e6e959 in cc::TileManager::FinishTasksAndCleanUp() tile_manager.cc:348
#2 0x109ed3c64 in cc::LayerTreeHostImpl::CleanUpTileManagerAndUIResources() layer_tree_host_impl.cc:2291
#3 0x109eec7fa in cc::LayerTreeHostImpl::ReleaseOutputSurface() layer_tree_host_impl.cc:2308
#4 0x109f6eb21 in cc::SingleThreadProxy::Stop() single_thread_proxy.cc:363
#5 0x109eb6764 in cc::LayerTreeHost::~LayerTreeHost() layer_tree_host.cc:386
#6 0x109eb807d in cc::LayerTreeHost::~LayerTreeHost() layer_tree_host.cc:372
#7 0x10ae27cc9 in ui::Compositor::~Compositor() memory:2540
#8 0x10ae2897d in ui::Compositor::~Compositor() compositor.cc:218
#9 0x10a8aed8d in views::BridgedNativeWidget::DestroyCompositor() memory:2540
#10 0x10a8addba in views::BridgedNativeWidget::~BridgedNativeWidget() bridged_native_widget.mm:374
#11 0x10a8af07d in views::BridgedNativeWidget::~BridgedNativeWidget() bridged_native_widget.mm:343
#12 0x10a9e845e in views::NativeWidgetMac::OnWindowWillClose() memory:2540
#13 0x7fff957bbbbb in __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ (CoreFoundation+0xa0bbb)
#14 0x7fff957bbb4e in ___CFXRegistrationPost_block_invoke (CoreFoundation+0xa0b4e)
#15 0x7fff957bbac6 in _CFXRegistrationPost (CoreFoundation+0xa0ac6)
#16 0x7fff957bb831 in ___CFXNotificationPost_block_invoke (CoreFoundation+0xa0831)
#17 0x7fff957785e1 in -[_CFXNotificationRegistrar find:object:observer:enumerator:] (CoreFoundation+0x5d5e1)
#18 0x7fff95777834 in _CFXNotificationPost (CoreFoundation+0x5c834)
#19 0x7fff92629179 in -[NSNotificationCenter postNotificationName:object:userInfo:] (Foundation+0x7179)
#20 0x7fff87520212 in __18-[NSWindow _close]_block_invoke (AppKit+0x2fd212)
#21 0x7fff87520114 in -[NSWindow _close] (AppKit+0x2fd114)
#22 0x7fff926b5b4d in __NSFireDelayedPerform (Foundation+0x93b4d)
#23 0x7fff957adb93 in __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__ (CoreFoundation+0x92b93)
#24 0x7fff957ad822 in __CFRunLoopDoTimer (CoreFoundation+0x92822)
#25 0x7fff957ad379 in __CFRunLoopDoTimers (CoreFoundation+0x92379)
#26 0x7fff957a4870 in __CFRunLoopRun (CoreFoundation+0x89870)
#27 0x7fff957a3ed7 in CFRunLoopRunSpecific (CoreFoundation+0x88ed7)
#28 0x7fff939f6934 in RunCurrentEventLoopInMode (HIToolbox+0x30934)
#29 0x7fff939f6676 in ReceiveNextEventCommon (HIToolbox+0x30676)
#30 0x7fff939f65ae in _BlockUntilNextEventMatchingListInModeWithFilter (HIToolbox+0x305ae)
#31 0x7fff8726bdf5 in _DPSNextEvent (AppKit+0x48df5)
#32 0x7fff8726b225 in -[NSApplication _nextEventMatchingEventMask:untilDate:inMode:dequeue:] (AppKit+0x48225)
#33 0x7fff8725fd7f in -[NSApplication run] (AppKit+0x3cd7f)
#34 0x109b3cbd3 in base::MessagePumpNSApplication::DoRun(base::MessagePump::Delegate*) message_pump_mac.mm:665
#35 0x109b3ab24 in base::MessagePumpCFRunLoopBase::Run(base::MessagePump::Delegate*) message_pump_mac.mm:238
#36 0x109b64595 in base::RunLoop::Run() run_loop.cc:35
#37 0x10a87055c in views::ViewsTestBase::TearDown() views_test_base.cc:61
#38 0x10b36fa3c in testing::TestInfo::Run() gtest.cc:2656
#39 0x10b370ce4 in testing::TestCase::Run() gtest.cc:2774
#40 0x10b382869 in testing::internal::UnitTestImpl::RunAllTests() gtest.cc:4647
#41 0x10b381ed9 in testing::UnitTest::Run() gtest.cc:2458
#42 0x109c0cc46 in base::TestSuite::Run() gtest.h:2237
#43 0x109c2a16a in base::(anonymous namespace)::LaunchUnitTestsInternal(base::Callback<int (), (base::internal::CopyMode)1> const&, int, int, bool, base::Callback<void (), (base::internal::CopyMode)1> const&) callback.h:389
#44 0x109c29df0 in base::LaunchUnitTests(int, char**, base::Callback<int (), (base::internal::CopyMode)1> const&) unit_test_launcher.cc:445
#45 0x10a8736eb in views::ViewsTestSuite::RunTests() views_test_suite.cc:32
#46 0x1098ef078 in main run_all_unittests_main.cc:8
#47 0x1094b18f3 in start (views_unittests+0x1000018f3)
#48 0x3 (<unknown module>)
0x6160000faf58 is located 216 bytes inside of 584-byte region [0x6160000fae80,0x6160000fb0c8)
freed by thread T0 here:
#0 0x10c90044b (libclang_rt.asan_osx_dynamic.dylib+0x5a44b)
#1 0x10a8074b2 in ui::TerminateContextFactoryForTests() context_factories_for_test.cc:42
#2 0x10a86c232 in views::ScopedViewsTestHelper::~ScopedViewsTestHelper() scoped_views_test_helper.cc:65
#3 0x10a8705ca in views::ViewsTestBase::TearDown() memory:2540
#4 0x10b36fa3c in testing::TestInfo::Run() gtest.cc:2656
#5 0x10b370ce4 in testing::TestCase::Run() gtest.cc:2774
#6 0x10b382869 in testing::internal::UnitTestImpl::RunAllTests() gtest.cc:4647
#7 0x10b381ed9 in testing::UnitTest::Run() gtest.cc:2458
#8 0x109c0cc46 in base::TestSuite::Run() gtest.h:2237
#9 0x109c2a16a in base::(anonymous namespace)::LaunchUnitTestsInternal(base::Callback<int (), (base::internal::CopyMode)1> const&, int, int, bool, base::Callback<void (), (base::internal::CopyMode)1> const&) callback.h:389
#10 0x109c29df0 in base::LaunchUnitTests(int, char**, base::Callback<int (), (base::internal::CopyMode)1> const&) unit_test_launcher.cc:445
#11 0x10a8736eb in views::ViewsTestSuite::RunTests() views_test_suite.cc:32
#12 0x1098ef078 in main run_all_unittests_main.cc:8
#13 0x1094b18f3 in start (views_unittests+0x1000018f3)
#14 0x3 (<unknown module>)
previously allocated by thread T0 here:
#0 0x10c8ffe4b (libclang_rt.asan_osx_dynamic.dylib+0x59e4b)
#1 0x10a807446 in ui::InitializeContextFactoryForTests(bool) context_factories_for_test.cc:37
#2 0x10a86bf7b in views::ScopedViewsTestHelper::ScopedViewsTestHelper(std::__1::unique_ptr<views::TestViewsDelegate, std::__1::default_delete<views::TestViewsDelegate> >) scoped_views_test_helper.cc:33
#3 0x10a870330 in views::ViewsTestBase::SetUp() views_test_base.cc:45
#4 0x10b36e00f in testing::Test::Run() gtest.cc:2458
#5 0x10b36fa3c in testing::TestInfo::Run() gtest.cc:2656
#6 0x10b370ce4 in testing::TestCase::Run() gtest.cc:2774
#7 0x10b382869 in testing::internal::UnitTestImpl::RunAllTests() gtest.cc:4647
#8 0x10b381ed9 in testing::UnitTest::Run() gtest.cc:2458
#9 0x109c0cc46 in base::TestSuite::Run() gtest.h:2237
#10 0x109c2a16a in base::(anonymous namespace)::LaunchUnitTestsInternal(base::Callback<int (), (base::internal::CopyMode)1> const&, int, int, bool, base::Callback<void (), (base::internal::CopyMode)1> const&) callback.h:389
#11 0x109c29df0 in base::LaunchUnitTests(int, char**, base::Callback<int (), (base::internal::CopyMode)1> const&) unit_test_launcher.cc:445
#12 0x10a8736eb in views::ViewsTestSuite::RunTests() views_test_suite.cc:32
#13 0x1098ef078 in main run_all_unittests_main.cc:8
#14 0x1094b18f3 in start (views_unittests+0x1000018f3)
#15 0x3 (<unknown module>)
SUMMARY: AddressSanitizer: heap-use-after-free tile_task_manager.cc:52 in cc::TileTaskManagerImpl::Shutdown()
,
Jun 30 2016
ContextMenuDisplayTest fails for a different reason, but the output was lost somehow. [ RUN ] TextfieldTest.ContextMenuDisplayTest ../../ui/views/controls/textfield/textfield_unittest.cc:639: Failure Expected: (GetClipboardText(ui::CLIPBOARD_TYPE_COPY_PASTE).empty()) != (menu->IsEnabledAt(4 )), actual: true vs true [ FAILED ] TextfieldTest.ContextMenuDisplayTest (33 ms) This is actually Issue 623442 But I'll leave the issue here for the ASAN problem.
,
Jun 30 2016
OK - so the problem here appears to be that in ultra-rare circumstances (more often with ASAN), a call to
[window performSelector:@selector(close) withObject:nil afterDelay:0];
doesn't get run when ViewsTestBase::TearDown() does
base::RunLoop run_loop;
run_loop.RunUntilIdle();
I've verified this in a Release asan build - changing the DCHECK in ViewsTestHelperMac::TearDown that verifies all the widgets are closed to a CHECK occasionally results in stuff like
[ RUN ] TextfieldTest.OverflowInRTLTest
[97988:1295:0630/142025:880954558846550:FATAL:views_test_helper_mac.mm(68)] Check failed: !Widget::GetWidgetForNativeWindow(window). Widget not closed.
0 views_unittests 0x0000000104efa793 _ZN4base5debug10StackTraceC1Ev + 19
1 views_unittests 0x0000000104f21dd8 _ZN7logging10LogMessageD2Ev + 392
2 views_unittests 0x0000000105c71b74 _ZN5views18ViewsTestHelperMac8TearDownEv + 788
3 views_unittests 0x0000000105c6ca5b _ZN5views21ScopedViewsTestHelperD2Ev + 107
4 views_unittests 0x0000000105c70efb _ZN5views13ViewsTestBase8TearDownEv + 299
5 views_unittests 0x000000010677183d _ZN7testing8TestInfo3RunEv + 1069
6 views_unittests 0x0000000106772ae5 _ZN7testing8TestCase3RunEv + 1301
7 views_unittests 0x000000010678466a _ZN7testing8internal12UnitTestImpl11RunAllTestsEv + 2250
8 views_unittests 0x0000000106783cda _ZN7testing8UnitTest3RunEv + 410
9 views_unittests 0x000000010500d577 _ZN4base9TestSuite3RunEv + 487
10 views_unittests 0x000000010502aa9b _ZN4base12_GLOBAL__N_123LaunchUnitTestsInternalERKNS_8CallbackIFivELNS_8internal8CopyModeE1EEEiibRKNS1_IFvvELS4_1EEE + 699
11 views_unittests 0x000000010502a721 _ZN4base15LaunchUnitTestsEiPPcRKNS_8CallbackIFivELNS_8internal8CopyModeE1EEE + 481
12 views_unittests 0x0000000105c742ac _ZN5views14ViewsTestSuite8RunTestsEv + 428
13 views_unittests 0x0000000104cef509 main + 201
14 views_unittests 0x00000001048b19f4 start + 52
On some random test that does Widget::Close() rather than Widget::CloseNow()
In NativeWidgetMac::Close(), changing
[window performSelector:@selector(close) withObject:nil afterDelay:0];
to
base::ThreadTaskRunnerHandle::Get()->PostTask(FROM_HERE, base::BindBlock(^() {
[window close];
}));
seems to be more robust.
,
Jun 30 2016
,
Jul 1 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/961644ad65fe2d43190d79e99f8b00a661026f6f commit 961644ad65fe2d43190d79e99f8b00a661026f6f Author: tapted <tapted@chromium.org> Date: Fri Jul 01 03:39:14 2016 Use PostTask, not performSelector in NativeWidgetMac::Close() In rare circumstances (more often with ASAN), a call to [window performSelector:@selector(close) withObject:nil afterDelay:0]; doesn't get run when ViewsTestBase::TearDown() does base::RunLoop run_loop; run_loop.RunUntilIdle(); ViewsTestBase then destroys other stuff. And, when the posted selector eventually gets executed, bad stuff happens. To fix, post a "regular" task, invoking -[NSWindow close]. Use a block to retain the window receiving the close. BUG= 624648 Review-Url: https://codereview.chromium.org/2115453002 Cr-Commit-Position: refs/heads/master@{#403400} [modify] https://crrev.com/961644ad65fe2d43190d79e99f8b00a661026f6f/ui/views/widget/native_widget_mac.mm
,
Jul 1 2016
|
||||
►
Sign in to add a comment |
||||
Comment 1 by horo@chromium.org
, Jun 30 2016Status: Assigned (was: Available)