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

Issue 810321 link

Starred by 1 user

Issue metadata

Status: Started
Owner:
OOO Dec 22 - Jan 8
Cc:
Components:
EstimatedDays: ----
NextAction: 2018-08-21
OS: Mac
Pri: 1
Type: ----



Sign in to add a comment

WebRtcBrowserTest.NegotiateNonCryptoCall flaky crashes on Mac

Project Member Reported by sheriff-...@appspot.gserviceaccount.com, Feb 8 2018

Issue description

Comment 1 by olka@chromium.org, Feb 8 2018

[23943:34567:0208/015210.088186:WARNING:peerconnection.cc(396)] Session description must have DTLS fingerprint if DTLS enabled.
[23943:34567:0208/015210.088313:ERROR:peerconnection.cc(1739)] Failed to set local offer sdp: Called with SDP without DTLS fingerprint. (INVALID_PARAMETER)
[23941:7175:0208/015210.092149:INFO:CONSOLE(16)] "Test Success", source: http://127.0.0.1:62974/media/webrtc_test_utilities.js (16)
[23941:33795:0208/015210.136357:FATAL:platform_handle.cc(130)] Check failed: platform_handle.type == MOJO_PLATFORM_HANDLE_TYPE_MACH_PORT (0 vs. 2)
0   content_browsertests                0x000000010a91e11c base::debug::StackTrace::StackTrace(unsigned long) + 28
1   content_browsertests                0x000000010a975945 logging::LogMessage::~LogMessage() + 645
2   content_browsertests                0x000000010be885f5 mojo::UnwrapSharedMemoryHandle(mojo::ScopedHandleBase<mojo::SharedBufferHandle>, base::SharedMemoryHandle*, unsigned long*, mojo::UnwrappedSharedMemoryHandleProtection*) + 741
3   content_browsertests                0x000000010eba1c58 media::SharedMemoryHandleProvider::InitFromMojoHandle(mojo::ScopedHandleBase<mojo::SharedBufferHandle>) + 632
4   content_browsertests                0x0000000104387258 video_capture::ReceiverMediaToMojoAdapter::OnNewBufferHandle(int, mojo::ScopedHandleBase<mojo::SharedBufferHandle>) + 296
5   content_browsertests                0x000000010581b712 video_capture::mojom::ReceiverStubDispatch::Accept(video_capture::mojom::Receiver*, mojo::Message*) + 1522
6   content_browsertests                0x000000010a134365 mojo::InterfaceEndpointClient::HandleValidatedMessage(mojo::Message*) + 3061
7   content_browsertests                0x000000010a132ba1 mojo::FilterChain::Accept(mojo::Message*) + 529
8   content_browsertests                0x000000010a137ebc mojo::InterfaceEndpointClient::HandleIncomingMessage(mojo::Message*) + 284
9   content_browsertests                0x000000010a149122 mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::internal::MultiplexRouter::MessageWrapper*, mojo::internal::MultiplexRouter::ClientCallBehavior, base::SequencedTaskRunner*) + 2786
10  content_browsertests                0x000000010a147498 mojo::internal::MultiplexRouter::Accept(mojo::Message*) + 872
11  content_browsertests                0x000000010a132ba1 mojo::FilterChain::Accept(mojo::Message*) + 529
12  content_browsertests                0x000000010a1273c0 mojo::Connector::ReadSingleMessage(unsigned int*) + 1280
13  content_browsertests                0x000000010a129555 mojo::Connector::ReadAllAvailableMessages() + 597
14  content_browsertests                0x000000010a128fc2 mojo::Connector::OnHandleReadyInternal(unsigned int) + 306
15  content_browsertests                0x0000000105a8fe36 mojo::SimpleWatcher::DiscardReadyState(base::RepeatingCallback<void (unsigned int)> const&, unsigned int, mojo::HandleSignalsState const&) + 342
16  content_browsertests                0x000000010be8c054 mojo::SimpleWatcher::OnHandleReady(int, unsigned int, mojo::HandleSignalsState const&) + 884
17  content_browsertests                0x000000010be8cc2b mojo::SimpleWatcher::Context::Notify(unsigned int, MojoHandleSignalsState, unsigned int) + 1979
18  content_browsertests                0x000000010be89374 mojo::SimpleWatcher::Context::CallNotify(unsigned long, unsigned int, MojoHandleSignalsState, unsigned int) + 20
19  content_browsertests                0x000000010a106e1c mojo::edk::Watch::InvokeCallback(unsigned int, mojo::HandleSignalsState const&, unsigned int) + 492
20  content_browsertests                0x000000010a0f8f94 mojo::edk::RequestContext::~RequestContext() + 2436
21  content_browsertests                0x000000010a0d2178 mojo::edk::NodeChannel::OnChannelMessage(void const*, unsigned long, std::__1::vector<mojo::edk::ScopedPlatformHandle, std::__1::allocator<mojo::edk::ScopedPlatformHandle> >) + 8504
22  content_browsertests                0x000000010a0a0e52 mojo::edk::Channel::OnReadComplete(unsigned long, unsigned long*) + 1890
23  content_browsertests                0x000000010a1191f8 mojo::edk::(anonymous namespace)::ChannelPosix::OnFileCanReadWithoutBlocking(int) + 1288
24  content_browsertests                0x000000010a9b6ab4 base::MessagePumpLibevent::OnLibeventNotification(int, short, void*) + 1300
25  content_browsertests                0x000000010ab97ef3 event_base_loop + 3923
26  content_browsertests                0x000000010a9b72de base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) + 526
27  content_browsertests                0x000000010a9aec80 base::MessageLoop::Run(bool) + 544
28  content_browsertests                0x000000010aa327bd base::RunLoop::Run() + 685
29  content_browsertests                0x000000010aade239 base::Thread::Run(base::RunLoop*) + 457
30  content_browsertests                0x000000010606641e content::BrowserThreadImpl::IOThreadRun(base::RunLoop*) + 238
31  content_browsertests                0x0000000106066781 content::BrowserThreadImpl::Run(base::RunLoop*) + 529
32  content_browsertests                0x000000010aadee6e base::Thread::ThreadMain() + 1774
33  content_browsertests                0x000000010aac94be base::(anonymous namespace)::ThreadFunc(void*) + 206
34  libsystem_pthread.dylib             0x00007fff94075899 _pthread_body + 138
35  libsystem_pthread.dylib             0x00007fff9407572a _pthread_struct_init + 0
36  libsystem_pthread.dylib             0x00007fff94079fc9 thread_start + 13

Comment 2 by olka@chromium.org, Feb 8 2018

The earliest crash I found:
[https://logs.chromium.org/v/?s=chromium%2Fbb%2Fchromium.memory%2FMac_ASan_64_Tests__1_%2F38373%2F%2B%2Frecipes%2Fsteps%2Fcontent_browsertests%2F0%2Fstdout]
(this build)
 [https://ci.chromium.org/buildbot/chromium.memory/Mac%20ASan%2064%20Tests%20(1)/38373]


[10515:37127:0204/144826.273119:WARNING:peerconnection.cc(395)] Session description must have DTLS fingerprint if DTLS enabled.
[10515:37127:0204/144826.273775:ERROR:peerconnection.cc(1736)] Failed to set local offer sdp: Called with SDP without DTLS fingerprint. (INVALID_PARAMETER)
[10509:7175:0204/144826.277380:INFO:CONSOLE(16)] "Test Success", source: http://127.0.0.1:55081/media/webrtc_test_utilities.js (16)
[10509:34307:0204/144826.336519:FATAL:platform_handle.cc(130)] Check failed: platform_handle.type == MOJO_PLATFORM_HANDLE_TYPE_MACH_PORT (0 vs. 2)
0   content_browsertests                0x0000000112a6678c base::debug::StackTrace::StackTrace(unsigned long) + 28
1   content_browsertests                0x0000000112abdf85 logging::LogMessage::~LogMessage() + 645
2   content_browsertests                0x0000000113fcfbc5 mojo::UnwrapSharedMemoryHandle(mojo::ScopedHandleBase<mojo::SharedBufferHandle>, base::SharedMemoryHandle*, unsigned long*, mojo::UnwrappedSharedMemoryHandleProtection*) + 741
3   content_browsertests                0x0000000116cd0c78 media::SharedMemoryHandleProvider::InitFromMojoHandle(mojo::ScopedHandleBase<mojo::SharedBufferHandle>) + 632
4   content_browsertests                0x000000010c4f4658 video_capture::ReceiverMediaToMojoAdapter::OnNewBufferHandle(int, mojo::ScopedHandleBase<mojo::SharedBufferHandle>) + 296
5   content_browsertests                0x000000010d973910 video_capture::mojom::ReceiverStubDispatch::Accept(video_capture::mojom::Receiver*, mojo::Message*) + 3664
6   content_browsertests                0x000000011227be55 mojo::InterfaceEndpointClient::HandleValidatedMessage(mojo::Message*) + 3061
7   content_browsertests                0x000000011227a691 mojo::FilterChain::Accept(mojo::Message*) + 529
8   content_browsertests                0x000000011227f9ac mojo::InterfaceEndpointClient::HandleIncomingMessage(mojo::Message*) + 284
9   content_browsertests                0x0000000112290c12 mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::internal::MultiplexRouter::MessageWrapper*, mojo::internal::MultiplexRouter::ClientCallBehavior, base::SequencedTaskRunner*) + 2786
10  content_browsertests                0x000000011228ef88 mojo::internal::MultiplexRouter::Accept(mojo::Message*) + 872
11  content_browsertests                0x000000011227a691 mojo::FilterChain::Accept(mojo::Message*) + 529
12  content_browsertests                0x000000011226eeb0 mojo::Connector::ReadSingleMessage(unsigned int*) + 1280
13  content_browsertests                0x0000000112271045 mojo::Connector::ReadAllAvailableMessages() + 597
14  content_browsertests                0x0000000112270ab2 mojo::Connector::OnHandleReadyInternal(unsigned int) + 306
15  content_browsertests                0x000000010dbdce26 mojo::SimpleWatcher::DiscardReadyState(base::RepeatingCallback<void (unsigned int)> const&, unsigned int, mojo::HandleSignalsState const&) + 342
16  content_browsertests                0x0000000113fd3624 mojo::SimpleWatcher::OnHandleReady(int, unsigned int, mojo::HandleSignalsState const&) + 884
17  content_browsertests                0x0000000113fd41fb mojo::SimpleWatcher::Context::Notify(unsigned int, MojoHandleSignalsState, unsigned int) + 1979
18  content_browsertests                0x0000000113fd0944 mojo::SimpleWatcher::Context::CallNotify(unsigned long, unsigned int, MojoHandleSignalsState, unsigned int) + 20
19  content_browsertests                0x000000011224e9cc mojo::edk::Watch::InvokeCallback(unsigned int, mojo::HandleSignalsState const&, unsigned int) + 492
20  content_browsertests                0x0000000112240b44 mojo::edk::RequestContext::~RequestContext() + 2436
21  content_browsertests                0x0000000112219d28 mojo::edk::NodeChannel::OnChannelMessage(void const*, unsigned long, std::__1::vector<mojo::edk::ScopedPlatformHandle, std::__1::allocator<mojo::edk::ScopedPlatformHandle> >) + 8504
22  content_browsertests                0x00000001121e8a02 mojo::edk::Channel::OnReadComplete(unsigned long, unsigned long*) + 1890
23  content_browsertests                0x0000000112260da8 mojo::edk::(anonymous namespace)::ChannelPosix::OnFileCanReadWithoutBlocking(int) + 1288
24  content_browsertests                0x0000000112afe944 base::MessagePumpLibevent::OnLibeventNotification(int, short, void*) + 1300
25  content_browsertests                0x0000000112cdfc83 event_base_loop + 3923
26  content_browsertests                0x0000000112aff16e base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) + 526
27  content_browsertests                0x0000000112af72c0 base::MessageLoop::Run(bool) + 544
28  content_browsertests                0x0000000112b7a30d base::RunLoop::Run() + 685
29  content_browsertests                0x0000000112c260b9 base::Thread::Run(base::RunLoop*) + 457
30  content_browsertests                0x000000010e1b136e content::BrowserThreadImpl::IOThreadRun(base::RunLoop*) + 238
31  content_browsertests                0x000000010e1b16d1 content::BrowserThreadImpl::Run(base::RunLoop*) + 529
32  content_browsertests                0x0000000112c26cee base::Thread::ThreadMain() + 1774
33  content_browsertests                0x0000000112c1133e base::(anonymous namespace)::ThreadFunc(void*) + 206
34  libsystem_pthread.dylib             0x00007fff905fa899 _pthread_body + 138
35  libsystem_pthread.dylib             0x00007fff905fa72a _pthread_struct_init + 0
36  libsystem_pthread.dylib             0x00007fff905fefc9 thread_start + 13
[890/1123] WebRtcBrowserTest.NegotiateNonCryptoCall (CRASHED)
Cc: maxmorin@chromium.org chfremer@chromium.org
Components: Internals>Media>Capture
Labels: OS-Mac
The stack trace you sent me by mail was for audio streams outliving the AudioManager, so there are probably multiple bugs making these tests flaky. Trying to figure out why the crash in this bug happens, it looks like |buffer_handle| is valid when it arrives in ReceiverMediaToMojoAdapter::OnNewBufferHandle, it eventually comes to https://cs.chromium.org/chromium/src/mojo/public/cpp/system/platform_handle.cc?type=cs&l=111 (it's |handle|). MojoUnwrapPlatformSharedBufferHandle returns MOJO_RESULT_OK, but platform_handle.type is MOJO_PLATFORM_HANDLE_TYPE_INVALID, causing the DCHECK on l. 130. That makes no sense.

+Christian for mojo video capture.

Comment 4 by olka@chromium.org, Feb 8 2018

The failure #3 references to is this:
https://ci.chromium.org/buildbot/chromium.memory/Mac%20ASan%2064%20Tests%20(1)/38443


[19481:34307:0206/221910.672225:WARNING:discardable_shared_memory_manager.cc(436)] Some MojoDiscardableSharedMemoryManagerImpls are still alive. They will be leaked.
[19481:7175:0206/221910.675015:FATAL:audio_manager_base.cc(122)] Check failed: input_streams_.empty().
0   content_browsertests                0x0000000116eb5cec base::debug::StackTrace::StackTrace(unsigned long) + 28
1   content_browsertests                0x0000000116f0d4e5 logging::LogMessage::~LogMessage() + 645
2   content_browsertests                0x00000001115b975a media::AudioManagerBase::~AudioManagerBase() + 458
3   content_browsertests                0x0000000111632bee media::AudioManagerMac::~AudioManagerMac() + 14
4   content_browsertests                0x00000001125c8944 content::BrowserMainLoop::~BrowserMainLoop() + 1764
5   content_browsertests                0x00000001125c90fe content::BrowserMainLoop::~BrowserMainLoop() + 14
6   content_browsertests                0x00000001125dc3a3 content::BrowserMainRunnerImpl::Shutdown() + 1251
7   content_browsertests                0x0000000116570251 ShellBrowserMain(content::MainFunctionParams const&, std::__1::unique_ptr<content::BrowserMainRunner, std::__1::default_delete<content::BrowserMainRunner> > const&) + 593
8   content_browsertests                0x00000001164aa217 content::ShellMainDelegate::RunProcess(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, content::MainFunctionParams const&) + 743
9   content_browsertests                0x000000011222b560 content::RunNamedProcessTypeMain(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, content::MainFunctionParams const&, content::ContentMainDelegate*) + 1248
10  content_browsertests                0x000000011222d0ba content::ContentMainRunnerImpl::Run() + 1354
11  content_browsertests                0x000000011b39ac13 service_manager::Main(service_manager::MainParams const&) + 5459
12  content_browsertests                0x000000011222afa0 content::ContentMain(content::ContentMainParams const&) + 368
13  content_browsertests                0x000000011639d298 content::BrowserTestBase::SetUp() + 5992
14  content_browsertests                0x0000000116369757 content::ContentBrowserTest::SetUp() + 1383
15  content_browsertests                0x00000001109e6860 testing::Test::Run() + 256
16  content_browsertests                0x00000001109e8ab4 testing::TestInfo::Run() + 900
17  content_browsertests                0x00000001109e9df7 testing::TestCase::Run() + 967
18  content_browsertests                0x0000000110a01627 testing::internal::UnitTestImpl::RunAllTests() + 2487
19  content_browsertests                0x0000000110a00bba testing::UnitTest::Run() + 298
20  content_browsertests                0x0000000116454479 base::TestSuite::Run() + 505
21  content_browsertests                0x000000011637920e content::ContentTestLauncherDelegate::RunTestSuite(int, char**) + 238
22  content_browsertests                0x00000001163fcb09 content::LaunchTests(content::TestLauncherDelegate*, unsigned long, int, char**) + 1081
23  content_browsertests                0x00000001163790ab main + 251
24  libdyld.dylib                       0x00007fff824345fd start + 1
[891/1116] WebRtcBrowserTest.NegotiateNonCryptoCall (CRASHED)

Comment 5 by olka@chromium.org, Feb 8 2018

Cc: phoglund@chromium.org
Status: Assigned (was: Available)
Looks like something is wrong with the test tear down?

Comment 6 by olka@chromium.org, Feb 8 2018

Status: Untriaged (was: Assigned)

Comment 7 by olka@chromium.org, Feb 8 2018

Cc: -chfremer@chromium.org
Owner: chfremer@chromium.org
Status: Assigned (was: Untriaged)
Disabling it here https://chromium-review.googlesource.com/c/chromium/src/+/908461,
assigning to the owner.

Comment 8 by olka@chromium.org, Feb 8 2018

Labels: -Sheriff-Chromium
Something related to audio device (aka media) thread being the main thread on Mac?
Project Member

Comment 9 by bugdroid1@chromium.org, Feb 8 2018

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

commit cfec3da62c47e7fd21b3e9ebe3ca65e8e3a4a8d2
Author: Olga Sharonova <olka@chromium.org>
Date: Thu Feb 08 15:12:54 2018

Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac

TBR=chfremer@chromium.org

Bug: 810321
Change-Id: Ia12ba855ab9fb8e66c9d48c8e66cf91f76f72e08
Reviewed-on: https://chromium-review.googlesource.com/908461
Reviewed-by: Olga Sharonova <olka@chromium.org>
Commit-Queue: Olga Sharonova <olka@chromium.org>
Cr-Commit-Position: refs/heads/master@{#535381}
[modify] https://crrev.com/cfec3da62c47e7fd21b3e9ebe3ca65e8e3a4a8d2/content/browser/webrtc/webrtc_browsertest.cc

Labels: Test-Disabled
Adding tests-disabled label (http://bit.ly/chrome-disabled-tests).
Project Member

Comment 11 by bugdroid1@chromium.org, Mar 5 2018

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

commit b8c86eb25d165739b4b83ca60f8bdd202f7f689a
Author: Greg Thompson <grt@chromium.org>
Date: Mon Mar 05 16:16:14 2018

Disable WebRtcMediaRecorderTest on macOS debug.

They all crash flakily during teardown with:

[42009:775:0305/032212.554804:FATAL:audio_manager_base.cc(122)] Check failed: input_streams_.empty().

BUG=810321
TBR=grt@chromium.org

Change-Id: Iec3ba5359d75cbdcca02d44eb1f603af47750ec7
Reviewed-on: https://chromium-review.googlesource.com/948545
Commit-Queue: Greg Thompson <grt@chromium.org>
Reviewed-by: Greg Thompson <grt@chromium.org>
Cr-Commit-Position: refs/heads/master@{#540831}
[modify] https://crrev.com/b8c86eb25d165739b4b83ca60f8bdd202f7f689a/content/browser/webrtc/webrtc_media_recorder_browsertest.cc

Cc: linds...@chromium.org
Labels: Hotlist-DisableReview
chfremer@ can you PTAL as this disabled reduces automated coverage?
Sorry for the delay. I'll do a mac build with dcheck-always-on and see what I can learn about these tests.
Alright, so just for clarity, I'd like to note that I believe there are multiple separate things being tracked here:

1.) WebRtcBrowserTest.NegotiateNonCryptoCall flaky crashes on "Builder Mac ASan 64 Tests (1)", for which there are at least two different crash stacks. 
1.a) One stack passes through video_capture::ReceiverMediaToMojoAdapter::OnNewBufferHandle() and ends in FATAL:platform_handle.cc(130)] Check failed: platform_handle.type == MOJO_PLATFORM_HANDLE_TYPE_MACH_PORT (0 vs. 2). 
1.b) The other stack ends in FATAL:audio_manager_base.cc(122)] Check failed: input_streams_.empty().

2.) WebRtcMediaRecorderTest crashes flakily on "Builder Mac10.13 Tests (dbg)" with a stack pointing to the same failed check as in 1.b).

The three symptoms may or may not have the same root cause.
Yeah I think WebRtcMediaRecorderTestgetting disabled should have had a separate tracker filed by the sheriff/reporter disabling the test, it's supposed to be one tracker per test disabled for this very reason. Thanks for clarifying whats going on though!
Sorry for the delay. This is still on my radar, but I was OOO for past 7 work days and am booked for focus work until Thursday this week. 

Current status is that I have so far been unsuccessful in reproducing the test failures on my Macbook with local builds. Unfortunately won't get the chance to continue investigating before Thursday.
Since I couldn't repro the WebRtcBrowserTest.NegotiateNonCryptoCall on my local Macbook Air, I am going to try on the bot via CQ, or if needed, temporarily re-enabling, in order to confirm this still happens.
Project Member

Comment 19 by bugdroid1@chromium.org, Apr 12 2018

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

commit b909c213c83ff68ac31491e628d9280ba31fe727
Author: Christian Fremerey <chfremer@chromium.org>
Date: Thu Apr 12 22:07:50 2018

Revert "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac"

This reverts commit cfec3da62c47e7fd21b3e9ebe3ca65e8e3a4a8d2.

Reason for revert: Checking if flakiness is still happening on Mac ASAN bot

Original change's description:
> Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac
>
> TBR=chfremer@chromium.org
>
> Bug: 810321
> Change-Id: Ia12ba855ab9fb8e66c9d48c8e66cf91f76f72e08
> Reviewed-on: https://chromium-review.googlesource.com/908461
> Reviewed-by: Olga Sharonova <olka@chromium.org>
> Commit-Queue: Olga Sharonova <olka@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#535381}

TBR=olka@chromium.org,chfremer@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug: 810321
Change-Id: I6e021bca934428cf9c94a34d4f0e874c25868033
Reviewed-on: https://chromium-review.googlesource.com/1010842
Commit-Queue: Christian Fremerey <chfremer@chromium.org>
Reviewed-by: Christian Fremerey <chfremer@chromium.org>
Cr-Commit-Position: refs/heads/master@{#550380}
[modify] https://crrev.com/b909c213c83ff68ac31491e628d9280ba31fe727/content/browser/webrtc/webrtc_browsertest.cc

After re-activating, the flakiness dashboard shows that this is still happening. We got 3 flaky crashes in 16 runs. 2 of the flakes were of type 1.b (as per comment #15) and one of type 1.a.

I built and ran locally on a Macbook Air with the same gn args and command-line used on the bot, and now was able to reproduce the issue there. I got 1 flake of type 1.a out of 20 runs so far. 

This should be a good starting point for digging into it.
Project Member

Comment 21 by bugdroid1@chromium.org, Apr 14 2018

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

commit 70038d924e2f0ddc561ef4cbd193df205471708c
Author: Christian Fremerey <chfremer@chromium.org>
Date: Sat Apr 14 02:50:32 2018

Reland "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac"

This reverts commit b909c213c83ff68ac31491e628d9280ba31fe727.

Reason for revert: Re-Disable the flaky test until a fix is found

Original change's description:
> Revert "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac"
> 
> This reverts commit cfec3da62c47e7fd21b3e9ebe3ca65e8e3a4a8d2.
> 
> Reason for revert: Checking if flakiness is still happening on Mac ASAN bot
> 
> Original change's description:
> > Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac
> >
> > TBR=chfremer@chromium.org
> >
> > Bug: 810321
> > Change-Id: Ia12ba855ab9fb8e66c9d48c8e66cf91f76f72e08
> > Reviewed-on: https://chromium-review.googlesource.com/908461
> > Reviewed-by: Olga Sharonova <olka@chromium.org>
> > Commit-Queue: Olga Sharonova <olka@chromium.org>
> > Cr-Commit-Position: refs/heads/master@{#535381}
> 
> TBR=olka@chromium.org,chfremer@chromium.org
> 
> # Not skipping CQ checks because original CL landed > 1 day ago.
> 
> Bug: 810321
> Change-Id: I6e021bca934428cf9c94a34d4f0e874c25868033
> Reviewed-on: https://chromium-review.googlesource.com/1010842
> Commit-Queue: Christian Fremerey <chfremer@chromium.org>
> Reviewed-by: Christian Fremerey <chfremer@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#550380}

TBR=olka@chromium.org,chfremer@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug: 810321
Change-Id: I68a7e09599e1511e8b4c547e7932e874689ab224
Reviewed-on: https://chromium-review.googlesource.com/1013018
Reviewed-by: Christian Fremerey <chfremer@chromium.org>
Commit-Queue: Christian Fremerey <chfremer@chromium.org>
Cr-Commit-Position: refs/heads/master@{#550867}
[modify] https://crrev.com/70038d924e2f0ddc561ef4cbd193df205471708c/content/browser/webrtc/webrtc_browsertest.cc

Project Member

Comment 22 by bugdroid1@chromium.org, Apr 17 2018

Labels: merge-merged-testbranch
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/b909c213c83ff68ac31491e628d9280ba31fe727

commit b909c213c83ff68ac31491e628d9280ba31fe727
Author: Christian Fremerey <chfremer@chromium.org>
Date: Thu Apr 12 22:07:50 2018

Revert "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac"

This reverts commit cfec3da62c47e7fd21b3e9ebe3ca65e8e3a4a8d2.

Reason for revert: Checking if flakiness is still happening on Mac ASAN bot

Original change's description:
> Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac
>
> TBR=chfremer@chromium.org
>
> Bug: 810321
> Change-Id: Ia12ba855ab9fb8e66c9d48c8e66cf91f76f72e08
> Reviewed-on: https://chromium-review.googlesource.com/908461
> Reviewed-by: Olga Sharonova <olka@chromium.org>
> Commit-Queue: Olga Sharonova <olka@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#535381}

TBR=olka@chromium.org,chfremer@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug: 810321
Change-Id: I6e021bca934428cf9c94a34d4f0e874c25868033
Reviewed-on: https://chromium-review.googlesource.com/1010842
Commit-Queue: Christian Fremerey <chfremer@chromium.org>
Reviewed-by: Christian Fremerey <chfremer@chromium.org>
Cr-Commit-Position: refs/heads/master@{#550380}
[modify] https://crrev.com/b909c213c83ff68ac31491e628d9280ba31fe727/content/browser/webrtc/webrtc_browsertest.cc

Project Member

Comment 23 by bugdroid1@chromium.org, Apr 17 2018

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

commit 70038d924e2f0ddc561ef4cbd193df205471708c
Author: Christian Fremerey <chfremer@chromium.org>
Date: Sat Apr 14 02:50:32 2018

Reland "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac"

This reverts commit b909c213c83ff68ac31491e628d9280ba31fe727.

Reason for revert: Re-Disable the flaky test until a fix is found

Original change's description:
> Revert "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac"
> 
> This reverts commit cfec3da62c47e7fd21b3e9ebe3ca65e8e3a4a8d2.
> 
> Reason for revert: Checking if flakiness is still happening on Mac ASAN bot
> 
> Original change's description:
> > Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac
> >
> > TBR=chfremer@chromium.org
> >
> > Bug: 810321
> > Change-Id: Ia12ba855ab9fb8e66c9d48c8e66cf91f76f72e08
> > Reviewed-on: https://chromium-review.googlesource.com/908461
> > Reviewed-by: Olga Sharonova <olka@chromium.org>
> > Commit-Queue: Olga Sharonova <olka@chromium.org>
> > Cr-Commit-Position: refs/heads/master@{#535381}
> 
> TBR=olka@chromium.org,chfremer@chromium.org
> 
> # Not skipping CQ checks because original CL landed > 1 day ago.
> 
> Bug: 810321
> Change-Id: I6e021bca934428cf9c94a34d4f0e874c25868033
> Reviewed-on: https://chromium-review.googlesource.com/1010842
> Commit-Queue: Christian Fremerey <chfremer@chromium.org>
> Reviewed-by: Christian Fremerey <chfremer@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#550380}

TBR=olka@chromium.org,chfremer@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug: 810321
Change-Id: I68a7e09599e1511e8b4c547e7932e874689ab224
Reviewed-on: https://chromium-review.googlesource.com/1013018
Reviewed-by: Christian Fremerey <chfremer@chromium.org>
Commit-Queue: Christian Fremerey <chfremer@chromium.org>
Cr-Commit-Position: refs/heads/master@{#550867}
[modify] https://crrev.com/70038d924e2f0ddc561ef4cbd193df205471708c/content/browser/webrtc/webrtc_browsertest.cc

Cc: roc...@chromium.org
Debugging this has been slow and not very fruitful so far, mostly because building the content_browsertests with ASan takes >1h, so too long to not context switch to other work.

I tried to dig into the Mojo code where the shared memory handle gets unwrapped and see at what point it is/becomes invalid, and it happened at code that is now changed.

Since there has been work done on that part of the code, see https://chromium-review.googlesource.com/c/chromium/src/+/987318, I rebased to the tip of tree, and with that the issue no longer seems to reproduce on my local build.

I'll re-enable the tests and see if the recent changes have magically resolved the flakiness, or if it has just shifted to something else.

+ rockot@ for visibility
Interesting. Thanks for looping me in. That CL should in theory be an effective no-op, but I wouldn't be terribly surprised if it ended up fixing some subtle bugs.
Project Member

Comment 26 by bugdroid1@chromium.org, Apr 24 2018

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

commit 9ca6829bda34281f6e5914bdc14dd99bd28d2dd2
Author: Christian Fremerey <chfremer@chromium.org>
Date: Tue Apr 24 02:12:50 2018

Revert "Reland "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac""

This reverts commit 70038d924e2f0ddc561ef4cbd193df205471708c.

Reason for revert: Flakiness may have been resolved with recent changes on tip of tree. No longer seems to repro on local build.

Original change's description:
> Reland "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac"
> 
> This reverts commit b909c213c83ff68ac31491e628d9280ba31fe727.
> 
> Reason for revert: Re-Disable the flaky test until a fix is found
> 
> Original change's description:
> > Revert "Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac"
> > 
> > This reverts commit cfec3da62c47e7fd21b3e9ebe3ca65e8e3a4a8d2.
> > 
> > Reason for revert: Checking if flakiness is still happening on Mac ASAN bot
> > 
> > Original change's description:
> > > Disable WebRtcBrowserTest.NegotiateNonCryptoCall on Mac
> > >
> > > TBR=chfremer@chromium.org
> > >
> > > Bug: 810321
> > > Change-Id: Ia12ba855ab9fb8e66c9d48c8e66cf91f76f72e08
> > > Reviewed-on: https://chromium-review.googlesource.com/908461
> > > Reviewed-by: Olga Sharonova <olka@chromium.org>
> > > Commit-Queue: Olga Sharonova <olka@chromium.org>
> > > Cr-Commit-Position: refs/heads/master@{#535381}
> > 
> > TBR=olka@chromium.org,chfremer@chromium.org
> > 
> > # Not skipping CQ checks because original CL landed > 1 day ago.
> > 
> > Bug: 810321
> > Change-Id: I6e021bca934428cf9c94a34d4f0e874c25868033
> > Reviewed-on: https://chromium-review.googlesource.com/1010842
> > Commit-Queue: Christian Fremerey <chfremer@chromium.org>
> > Reviewed-by: Christian Fremerey <chfremer@chromium.org>
> > Cr-Commit-Position: refs/heads/master@{#550380}
> 
> TBR=olka@chromium.org,chfremer@chromium.org
> 
> # Not skipping CQ checks because original CL landed > 1 day ago.
> 
> Bug: 810321
> Change-Id: I68a7e09599e1511e8b4c547e7932e874689ab224
> Reviewed-on: https://chromium-review.googlesource.com/1013018
> Reviewed-by: Christian Fremerey <chfremer@chromium.org>
> Commit-Queue: Christian Fremerey <chfremer@chromium.org>
> Cr-Commit-Position: refs/heads/master@{#550867}

TBR=olka@chromium.org,chfremer@chromium.org

# Not skipping CQ checks because original CL landed > 1 day ago.

Bug: 810321
Change-Id: Ie796bb3b206c6855d9859d8f18ec008e7ac4892a
Reviewed-on: https://chromium-review.googlesource.com/1024746
Reviewed-by: Christian Fremerey <chfremer@chromium.org>
Commit-Queue: Christian Fremerey <chfremer@chromium.org>
Cr-Commit-Position: refs/heads/master@{#552957}
[modify] https://crrev.com/9ca6829bda34281f6e5914bdc14dd99bd28d2dd2/content/browser/webrtc/webrtc_browsertest.cc

The dashboard shows 

https://test-results.appspot.com/dashboards/flakiness_dashboard.html#testType=content_browsertests&tests=WebRtcBrowserTest.NegotiateNonCryptoCall

we still have flaky crashes in 5 out of 21 runs (16 regular + 5 retries). All 5 cases now show the stack trace ending in audio_manager_base.cc:

[76716:775:0423/234643.523911:FATAL:audio_manager_base.cc(122)] Check failed: input_streams_.empty().
0   content_browsertests                0x0000000110978dbc base::debug::StackTrace::StackTrace(unsigned long) + 28
1   content_browsertests                0x000000011077b257 logging::LogMessage::~LogMessage() + 695
2   content_browsertests                0x000000010a533a8d media::AudioManagerBase::~AudioManagerBase() + 461
3   content_browsertests                0x000000010a5b197e media::AudioManagerMac::~AudioManagerMac() + 14
4   content_browsertests                0x000000010e27ea19 content::BrowserMainLoop::~BrowserMainLoop() + 1561
5   content_browsertests                0x000000010e27f16e content::BrowserMainLoop::~BrowserMainLoop() + 14
6   content_browsertests                0x000000010e29145f content::BrowserMainRunnerImpl::Shutdown() + 1103

But I also found an error log showing what may be the new symptom of the other crash stack where it had the invalid shared buffer handle:
[76716:22019:0423/234643.513949:ERROR:shared_buffer_dispatcher.cc(161)] Invalid serialized shared buffer dispatcher (invalid num_bytes?)

Will need to continue to investigate.
Hmm, might be related to how mac rounds the requested number of bytes up when allocating shared memory?
"invalid num_bytes" means only that the region size was deserialized as zero, which -- assuming no message corruption -- means an invalid shared buffer handle was serialized somehow. So possibly just the same old issue presenting itself differently.
Since the issue 1a from #15 seems to no longer cause a crashable offense, I started looking into 1b, which is the stack trace from #27.

The cause seems to be a race condition during browser shutdown. The following can happen:
On the UI thread:
1. BrowserMainLoop::ShutdownThreadsAndCleanUp() starts executing on the UI thread
2. BrowserMainLoop::ShutdownThreadsAndCleanUp() joins the IO thread.
On the IO thread:
3. AudioInputDelegateImpl is destroyed
4. AudioInputController::DoClose() gets posted to the "audio thread" (which is the UI thread on Mac OS)
On the UI thread:
5. BrowserMainLoop is destroyed and as part of it, AudioManager is destroyed.
=> CHECK in ~AudioManagerBase() fails because AudioInputController::DoClose() has not run yet.

This probably only happens on Mac OS, because on other platforms, the "audio thread" is a dedicated thread and, probably, this thread is joined on the UI thread before/while AudioManager is destroyed, specifically, before ~AudioManagerBase() runs.

maxmorin@ or olka@, would it be safe to just remove the CHECK or is it required that we fix this race and ensure that AudioInputController::DoClose() gets executed?
Based on #30, it seems likely that the same issue caused the flakiness in  WebRtcMediaRecorderTest, so once we have a fix, we should be able to re-enable both.
Oh, https://cs.chromium.org/chromium/src/media/audio/mac/audio_manager_mac.cc?sq=package:chromium&l=514 is supposed to clean the streams up anyways but I suppose a stream creation could happen after ShutdownOnAudioThread. I'm not sure we can just ignore the input_streams_.empty(), these streams might have threads running, on which they might use various things after free. Maybe we can return nullptr from the Make*Stream functions if |is_shutdown| is set?
I checked and found that AudioManagerMac::ShutdownOnAudioThread() does get called and run in the problematic case. I can repro at 100% by adding a 1 second sleep right before step 4 from #30.

Based on reading the implementation of it, it looks like AudioManagerMac::ShutdownOnAudioThread() only closes some streams that are private to AudioManagerMac, but it does not touch AudioManagerBase::input_streams_.
Oooh, I get it now. It does actually touch |input_streams_| in a very roundabout way. When it creates streams, it adds them to its internal stream collections before returning (so every stream is stored in both the base class and the subclass). When closing streams, they are similarly removed from the internal stream collection in addition to being deleted by the base class. However, fake streams are not created the same way as normal streams (https://cs.chromium.org/chromium/src/media/audio/audio_manager_base.cc?l=275), and are not stored by the subclass. We could probably fix the flakiness by using |input_streams_| directly from AudioManagerMac instead of having additional collections.

Comment 35 by olka@chromium.org, May 18 2018

Owner: olka@chromium.org

Comment 36 by olka@chromium.org, May 18 2018

Status: Started (was: Assigned)
Project Member

Comment 37 by bugdroid1@chromium.org, May 21 2018

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

commit 93e610780fba13bc4a1dc9c4b23ca8434e3f5732
Author: Olga Sharonova <olka@chromium.org>
Date: Mon May 21 09:00:24 2018

When closing input streams on Mac iterate throug base input streams.

AudioManagerBase input streams may contain fake streams, which are not
closed properly on Mac now. Fixing it.

Bug: 810321
Cq-Include-Trybots: luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel
Change-Id: I117da2df47c99f43c2d122be8af4ca43da87531d
Reviewed-on: https://chromium-review.googlesource.com/1065679
Reviewed-by: Max Morin <maxmorin@chromium.org>
Commit-Queue: Olga Sharonova <olka@chromium.org>
Cr-Commit-Position: refs/heads/master@{#560250}
[modify] https://crrev.com/93e610780fba13bc4a1dc9c4b23ca8434e3f5732/media/audio/audio_manager_base.cc
[modify] https://crrev.com/93e610780fba13bc4a1dc9c4b23ca8434e3f5732/media/audio/audio_manager_base.h
[modify] https://crrev.com/93e610780fba13bc4a1dc9c4b23ca8434e3f5732/media/audio/mac/audio_manager_mac.cc

Comment 38 by olka@chromium.org, May 29 2018

Now it flakily crashes like this on Mac ASan 64 Tests (1) (example https://chromium-swarm.appspot.com/task?id=3dc485932ac45010&refresh=10&show_raw=1):

[61313:30979:0529/045622.884095:WARNING:audio_input_sync_writer.cc(369)] AISW: No room in socket buffer.: Broken pipe (32)
[61313:775:0529/045622.882288:FATAL:fake_audio_input_stream.cc(69)] Check failed: !callback_.
0   content_browsertests                0x00000001151fae4c base::debug::StackTrace::StackTrace(unsigned long) + 28
1   content_browsertests                0x0000000115002547 logging::LogMessage::~LogMessage() + 695
2   content_browsertests                0x000000010e90e809 media::FakeAudioInputStream::Close() + 521
3   content_browsertests                0x000000010e8cfdc6 media::AudioManagerBase::CloseAllInputStreams() + 246
4   content_browsertests                0x000000010e940d52 media::AudioManagerMac::ShutdownOnAudioThread() + 242
5   content_browsertests                0x000000010e8c5faf media::AudioManager::Shutdown() + 623
6   content_browsertests                0x00000001128b446d content::BrowserMainLoop::ShutdownThreadsAndCleanUp() + 5149
7   content_browsertests                0x00000001128bbabc content::BrowserMainRunnerImpl::Shutdown() + 1004
8   content_browsertests                0x000000011466e301 ShellBrowserMain(content::MainFunctionParams const&, std::__1::unique_ptr<content::BrowserMainRunner, std::__1::default_delete<content::BrowserMainRunner> > const&) + 593
9   content_browsertests                0x000000011457bed6 content::ShellMainDelegate::RunProcess(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, content::MainFunctionParams const&) + 742
10  content_browsertests                0x00000001124cd0b7 content::RunBrowserProcessMain(content::MainFunctionParams const&, content::ContentMainDelegate*, std::__1::unique_ptr<content::BrowserProcessSubThread, std::__1::default_delete<content::BrowserProcessSubThread> >) + 311
11  content_browsertests                0x00000001124cfc85 content::ContentMainRunnerImpl::Run() + 1541
12  content_browsertests                0x000000011924038d service_manager::Main(service_manager::MainParams const&) + 5501
13  content_browsertests                0x000000010fdead01 content::ContentMain(content::ContentMainParams const&) + 353
14  content_browsertests                0x000000011443bc26 content::BrowserTestBase::SetUp() + 6054
15  content_browsertests                0x00000001144038cf content::ContentBrowserTest::SetUp() + 1375
16  content_browsertests                0x000000010f1a9005 testing::Test::Run() + 293
17  content_browsertests                0x000000010f1ab466 testing::TestInfo::Run() + 950
18  content_browsertests                0x000000010f1ac8d7 testing::TestCase::Run() + 999
19  content_browsertests                0x000000010f1d1e77 testing::internal::UnitTestImpl::RunAllTests() + 2775
20  content_browsertests                0x000000010f1d12ce testing::UnitTest::Run() + 382
21  content_browsertests                0x000000011450b167 base::TestSuite::Run() + 503
22  content_browsertests                0x00000001144148fe content::ContentTestLauncherDelegate::RunTestSuite(int, char**) + 238
23  content_browsertests                0x00000001144a59da content::LaunchTests(content::TestLauncherDelegate*, unsigned long, int, char**) + 1034
24  content_browsertests                0x000000011441479f main + 255
25  libdyld.dylib                       0x00007fff64efa115 start + 1
26  ???                                 0x000000000000000c 0x0 + 12

[917/1267] WebRtcBrowserTest.NegotiateNonCryptoCall (CRASHED)

Comment 39 by olka@chromium.org, May 29 2018

Someone did not stop the stream?
Well, when we close it from the audio manager, we don't stop it first. I figured this was ok, but I guess not?
NextAction: 2018-08-21
The NextAction date has arrived: 2018-08-21
Cc: -roc...@chromium.org rockot@google.com

Sign in to add a comment