New issue
Advanced search Search tips

Issue 692857 link

Starred by 1 user
Status: Fixed
Owner:
dalecur...@chromium.org
Closed: Feb 2017
Cc:
maxmorin@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Mac
Pri: 3
Type: Bug



Sign in to add a comment

Check failed: poll_callbacks_.find(qualified_id) == poll_callbacks_.end().

Project Member Reported by erikc...@chromium.org, Feb 16 2017 
I tried opening a bunch of pages from cnn.com [world, news, travel ,etc] in separate tabs. I had 10 paused youtube videos open as well.
TOT: 618b40d65c8372e95c3fb7bf848560b2a9b14a34
  5 dcheck_always_on = true                                                         
  6 is_component_build = false                                                      
  7 is_debug = false                                                                
  8 symbol_level = 1                                                                
  9 use_goma = true                                                                 
 10 enable_profiling = true  


[33234:1295:0215/170444.063861:ERROR:media_router_mojo_impl.cc(811)] MR #6fd788c9-5bd3-4283-ba3a-3a626548d591: Reached max queue size. Dropping oldest request.
[33234:1295:0215/170445.049025:ERROR:media_router_mojo_impl.cc(811)] MR #6fd788c9-5bd3-4283-ba3a-3a626548d591: Reached max queue size. Dropping oldest request.
[33234:1295:0215/170445.630302:FATAL:audio_stream_monitor.cc(135)] Check failed: poll_callbacks_.find(qualified_id) == poll_callbacks_.end(). 
0   Chromium Framework                  0x000000010864228c base::debug::StackTrace::StackTrace(unsigned long) + 28
1   Chromium Framework                  0x0000000108667923 logging::LogMessage::~LogMessage() + 67
2   Chromium Framework                  0x0000000106b43a82 content::AudioStreamMonitor::StartMonitoringStreamOnUIThread(int, int, base::Callback<std::__1::pair<float, bool> (), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&) + 338
3   Chromium Framework                  0x0000000106b43551 content::AudioStreamMonitor::StartMonitoringHelper(int, int, int, base::Callback<std::__1::pair<float, bool> (), (base::internal::CopyMode)1, (base::internal::RepeatMode)1> const&) + 209
4   Chromium Framework                  0x0000000108642c35 base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*) + 309
5   Chromium Framework                  0x0000000108680349 base::MessageLoop::RunTask(base::PendingTask*) + 441
6   Chromium Framework                  0x000000010868070c base::MessageLoop::DeferOrRunPendingTask(base::PendingTask) + 44
7   Chromium Framework                  0x0000000108680c13 base::MessageLoop::DoWork() + 483
8   Chromium Framework                  0x0000000108685840 base::MessagePumpCFRunLoopBase::RunWork() + 48
9   Chromium Framework                  0x0000000108668d9a base::mac::CallWithEHFrame(void () block_pointer) + 10
10  Chromium Framework                  0x0000000108685214 base::MessagePumpCFRunLoopBase::RunWorkSource(void*) + 68
11  CoreFoundation                      0x00007fff847857e1 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
12  CoreFoundation                      0x00007fff84764f1c __CFRunLoopDoSources0 + 556
13  CoreFoundation                      0x00007fff8476443f __CFRunLoopRun + 927
14  CoreFoundation                      0x00007fff84763e38 CFRunLoopRunSpecific + 296
15  HIToolbox                           0x00007fff9693f935 RunCurrentEventLoopInMode + 235
16  HIToolbox                           0x00007fff9693f76f ReceiveNextEventCommon + 432
17  HIToolbox                           0x00007fff9693f5af _BlockUntilNextEventMatchingListInModeWithFilter + 71
18  AppKit                              0x00007fff959dadf6 _DPSNextEvent + 1067
19  AppKit                              0x00007fff959da226 -[NSApplication _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 454
20  Chromium Framework                  0x0000000108078870 __71-[BrowserCrApplication nextEventMatchingMask:untilDate:inMode:dequeue:]_block_invoke + 64
21  Chromium Framework                  0x0000000108668d9a base::mac::CallWithEHFrame(void () block_pointer) + 10
22  Chromium Framework                  0x00000001080787a9 -[BrowserCrApplication nextEventMatchingMask:untilDate:inMode:dequeue:] + 169
23  AppKit                              0x00007fff959ced80 -[NSApplication run] + 682
24  Chromium Framework                  0x00000001086863e7 base::MessagePumpNSApplication::DoRun(base::MessagePump::Delegate*) + 359
25  Chromium Framework                  0x0000000108685697 base::MessagePumpCFRunLoopBase::Run(base::MessagePump::Delegate*) + 119
26  Chromium Framework                  0x0000000108680072 base::MessageLoop::RunHandler() + 354
27  Chromium Framework                  0x00000001086b7097 base::RunLoop::Run() + 151
28  Chromium Framework                  0x000000010807e96f ChromeBrowserMainParts::MainMessageLoopRun(int*) + 303
29  Chromium Framework                  0x00000001068dcc44 content::BrowserMainLoop::RunMainMessageLoopParts() + 52
30  Chromium Framework                  0x00000001068e0606 content::BrowserMainRunnerImpl::Run() + 166
31  Chromium Framework                  0x00000001068d817c content::BrowserMain(content::MainFunctionParams const&) + 124
32  Chromium Framework                  0x0000000108019000 content::ContentMainRunnerImpl::Run() + 528
33  Chromium Framework                  0x0000000108018076 content::ContentMain(content::ContentMainParams const&) + 54
34  Chromium Framework                  0x000000010612f8bb ChromeMain + 75
35  Chromium                            0x0000000105ec7d9a main + 522
36  libdyld.dylib                       0x00007fff888ac5ad start + 1

Comment 1 by dalecur...@chromium.org, Feb 16 2017

Cc: -dalecur...@chromium.org maxmorin@chromium.org
Owner: dalecur...@chromium.org
Status: Assigned (was: Untriaged)
Thanks for the report, this is surprising. I added that check recently and don't see any obvious ways we could be hitting this code path twice.

We have checks in AudioRendererHost which verify that stream_id is unique per process and AudioOutputDelegateImpl::UpdatePlayingState(false) is always called during destruction of that class; I can't find any ordering issues given that constraint.

Will do some testing tomorrow to see what gives here. +maxmorin who might see something I've missed.

Comment 2 by erikc...@chromium.org, Feb 16 2017

Labels: OS-Mac
This was on macOS 10.11.6, I think you have all the other context.

Comment 3 by dalecur...@chromium.org, Feb 16 2017 

Haven't tested yet, but any weird chrome://flags or command line switches?

Comment 4 by erikc...@chromium.org, Feb 16 2017 

--enable-heap-profiling=native [with a local change to make it work], but it should *theoretically* have no effect on this.

nothing funny in chrome://flags

Comment 5 by maxmorin@chromium.org, Feb 16 2017 

Hmm, the only way this could happen, as far as I can see, is if pausing and playing happens to result in "startmonitoring" arriving on the UI thread before "stopmonitoring", but that would mean BrowserThread::PostTask is reordering the calls (which I really hope it's not doing). :) Very strange.

Comment 6 by dalecur...@chromium.org, Feb 16 2017 

I have a vague hunch something might be going awry with the WeakPtr usage, so StopMonitoring calls are dropped in some weird case. But it's hard to see how since destruction should ensure that never happens.

Comment 7 by maxmorin@chromium.org, Feb 16 2017 

~WeakPtrFactory do invalidate the pointers, right? I just assumed it did (because it would be very confusing if it didn't). I'll have a closer look tomorrow.

Comment 8 by dalecur...@chromium.org, Feb 16 2017 

It does so automatically; I'm more worried that there's a Stop posted that doesn't get executed somewhere along the path, but the ~destructor should handle that...

Comment 9 by dalecur...@chromium.org, Feb 17 2017 

Was able to reproduce using http://mounirlamouri.github.io/sandbox/autoplay/test.html - then clicking kill process in the task manager and then reload on the subsequent sad tab.

The issue is that WebContents::FromRenderFrameHost() stops working, but the associated WebContentsImpl which owns the AudioStreamMonitor stays alive; thus the static helper can't route the stop calls to the ASM. The reload reuses the RPH and the stream ids end up matching so we hit the dcheck.

Looking at what we should be doing here now.

Comment 10 by erikc...@chromium.org, Feb 17 2017 

Thank you for continuing to dig until you found a repro. :)

Comment 11 by dalecur...@chromium.org, Feb 17 2017 

Thanks for filing and thanks to maxmorin@ for suggesting the DCHECK(), it's exposed some long standing bad behavior!
Project Member

Comment 13 by bugdroid1@chromium.org, Feb 20 2017 

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

commit 3d1e1301ee8f7c1cab24e2d161218336ea0e7b7c
Author: dalecurtis <dalecurtis@chromium.org>
Date: Mon Feb 20 22:33:25 2017

Fix teardown of stale AudioStreamMonitor poll callbacks.

It's possible for the RenderProcessHost and WebContents (and thus AudioStreamMonitor) to
survive the death of the render process and subsequently be reused. During this
period StartStopMonitoringHelper() will be unable to lookup the WebContents
using the now-dead |render_frame_id|. We must thus have a secondary mechanism for clearing stale callbacks.

This change introduces AudioStreamMonitor:RenderProcessGone() which is called by
the WebContents whenever WCO::RenderProcessGone() is. This allows the audio stream
monitor to clear stale callbacks that the AudioOutputDelegateImpl will no longer
be able to route to it.

Subsequently this also fixes a bug on Android (and anywhere else power monitoring
is disabled), where process termination would not correctly clear the audible
state for a process.

On all platforms this fixes a minor leak of AudioOutputController objects, since
they are bound by ref-ptr into the callback map containing stale entries. I say
minor since they would immediately be overwritten if the process is reusued or
tossed completely when the WebContents object goes away.

BUG= 692857 
TEST=new unittest, manual test:
1. load http://mounirlamouri.github.io/sandbox/autoplay/test.html
2. kill process from task manager.
3. click the reload button == boom (boom no longer after patch!).

Review-Url: https://codereview.chromium.org/2698813007
Cr-Commit-Position: refs/heads/master@{#451664}

[modify] https://crrev.com/3d1e1301ee8f7c1cab24e2d161218336ea0e7b7c/content/browser/media/audio_stream_monitor.cc
[modify] https://crrev.com/3d1e1301ee8f7c1cab24e2d161218336ea0e7b7c/content/browser/media/audio_stream_monitor.h
[modify] https://crrev.com/3d1e1301ee8f7c1cab24e2d161218336ea0e7b7c/content/browser/media/audio_stream_monitor_unittest.cc
[modify] https://crrev.com/3d1e1301ee8f7c1cab24e2d161218336ea0e7b7c/content/browser/web_contents/web_contents_impl.cc

Comment 14 by dalecur...@chromium.org, Feb 21 2017

Status: Fixed (was: Assigned)
Should be fixed, let me know if you see it again!
►

Sign in to add a comment