New issue
Advanced search Search tips

Issue 624648 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Jul 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Mac
Pri: 1
Type: ----



Sign in to add a comment

Build failure: views_unittests is flakey in Mac ASan 64 Tests (1) Build

Project Member Reported by horo@chromium.org, Jun 30 2016

Issue description

Build 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

 

Comment 1 by horo@chromium.org, Jun 30 2016

Owner: karandeepb@chromium.org
Status: Assigned (was: Available)
karandeepb@
Could you please take a look?
Components: Tests>Flaky Internals>Views
Labels: -Pri-2 Proj-MacViews OS-Mac Pri-1
Owner: tapted@chromium.org
This is similar to another flaky test which was disabled recently -  http://crbug.com/624555 . Over to Trent who has a patch for it.

Comment 3 by tapted@chromium.org, 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()

Comment 4 by tapted@chromium.org, 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.

Comment 5 by tapted@chromium.org, Jun 30 2016

Status: Started (was: Assigned)
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.
Project Member

Comment 7 by bugdroid1@chromium.org, 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

Status: Fixed (was: Started)

Sign in to add a comment