Adds more logging for audio input issues.

media/audio/audio_input_controller.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "media/audio/audio_input_controller.h"
 
 #include "base/bind.h"
 #include "base/threading/thread_restrictions.h"
 #include "media/base/limits.h"
 #include "media/base/scoped_histogram_timer.h"
@@ skipping 184 matching lines @@
 
   if (stream_ && !stream_->Open()) {
     stream_->Close();
     stream_ = NULL;
     handler_->OnError(this, STREAM_OPEN_ERROR);
     return;
   }
 
   DCHECK(!no_data_timer_.get());
 
-  // This is a fix for crbug.com/357501.  The timer can trigger when closing

[DaleCurtis, 2014/04/09 22:16:11]

Instead of this, all streams should be paused when suspend starts and resumed
some time after resume comes back. It shouldn't be too hard to do this, but
different than AudioOutputStreams since AudioInputController owns the raw stream
vs a proxy object.

Each AudioInputController could listen for power events and then pause upon
suspend and restart the stream upon resume (keeping the renderer process
oblivious).

Streams should not be started within x seconds of resume either, so the
AudioManager should probably still maintain a ShouldDeferStreamStart() method
which can be called by the controllers.

[jiayl, 2014/04/09 22:24:57]

That's reasonable but beyond the scope of this change.
This is not trying to fix any code bug but adding log messages to help us
understand where the problem is when audio input is dropped.

[DaleCurtis, 2014/04/09 22:34:18]

Agreed, but I don't think you should enable the no data timer here either.
Ignoring the error later is also kind of sketchy. I'd just stick to adding the
logging. I'm really the peanut gallery here though, so I defer tommi@, xians@,
henrika@ :)

[jiayl, 2014/04/09 22:43:24]

Yeah, I should have explained it.
We have to enable the timer to know if the input data stops coming in.
It would be better if we simply not fire the NO_DATA_ERROR when the timer
callback happens. But unfortunately the webrtc logging methods are only
available inside content/, not from AudioInputController. That means we need
some way to pass the log message to the content layer, while the EventHandler is
the only existing connection.

So we either 1) fire the error for logging and make EventHandler ignore the
error, or 2) add a new method like OnLogMessage to the EventHandler interface.

I chose 1) because it's less code so better for merging.

[no longer working on chromium, 2014/04/10 09:55:02]

I also believe hooking up ShouldDeferStreamStart to the input code is necessary
to be done here. I am going to create a bug for it.
As Jiayang pointed out, lets do it in a separate Cl.

[no longer working on chromium, 2014/04/10 09:55:02]

I hope the current code will just be temporary to allow us collect some
information on if we are still hitting the NO_DATA_ERROR in unexpected cases.

Hopefully we will remove it completely (if NO_DATA_ERROR does not happen any
more) or somehow handle the error in another way (if NO_DATA_ERROR happens quite
often).

I talked to Henrik offline, and he said we'd better get some logs so that we
would understand more before taking another steps.

So I would just defer to Tommi on if this is a good way to add log or do it
another way.

-  // the lid on Macs, which causes more problems than the timer fixes.
-  // Also, in crbug.com/357569, the goal is to remove usage of this timer
-  // since it was added to solve a crash on Windows that no longer can be
-  // reproduced.
+  // The timer is enabled for logging purposes. The NO_DATA_ERROR triggered
+  // from the timer must be ignored by the EventHandler.
   // TODO(henrika): remove usage of timer when it has been verified on Canary
   // that we are safe doing so. Goal is to get rid of |no_data_timer_| and
-  // everything that is tied to it.
-  enable_nodata_timer = false;
+  // everything that is tied to it. crbug.com/357569.
+  enable_nodata_timer = true;
 
   if (enable_nodata_timer) {
     // Create the data timer which will call DoCheckForNoData(). The timer
     // is started in DoRecord() and restarted in each DoCheckForNoData()
     // callback.
     no_data_timer_.reset(new base::Timer(
         FROM_HERE, base::TimeDelta::FromSeconds(kTimerInitialIntervalSeconds),
         base::Bind(&AudioInputController::DoCheckForNoData,
                    base::Unretained(this)), false));
   } else {
@@ skipping 92 matching lines @@
   stream_->SetAutomaticGainControl(enabled);
 }
 
 void AudioInputController::DoCheckForNoData() {
   DCHECK(task_runner_->BelongsToCurrentThread());
 
   if (!GetDataIsActive()) {
     // The data-is-active marker will be false only if it has been more than
     // one second since a data packet was recorded. This can happen if a
     // capture device has been removed or disabled.
     handler_->OnError(this, NO_DATA_ERROR);

[no longer working on chromium, 2014/04/10 09:55:02]

Tommi, on the output side, Dale added a
Media.AudioOutputControllerPlaybackStartupSuccess to keep track if getting a
OnMoreData callback within 5 seconds after the stream is started.
From the histogram, it reports an average of 0.45% failure on Mac, while it is
about 0..1% on other platforms.

should we also put some UMA stats here for the input?

It probably should be done on another CL though.

-    return;
   }
 
   // Mark data as non-active. The flag will be re-enabled in OnData() each
   // time a data packet is received. Hence, under normal conditions, the
   // flag will only be disabled during a very short period.
   SetDataIsActive(false);
 
   // Restart the timer to ensure that we check the flag again in
   // |kTimerResetIntervalSeconds|.
   no_data_timer_->Start(
@@ skipping 59 matching lines @@
 
 void AudioInputController::SetDataIsActive(bool enabled) {
   base::subtle::Release_Store(&data_is_active_, enabled);
 }
 
 bool AudioInputController::GetDataIsActive() {
   return (base::subtle::Acquire_Load(&data_is_active_) != false);
 }
 
 }  // namespace media