Improve logging related to start/stop and failure of audio input streams in Chrome

media/audio/audio_input_controller.cc

Index: media/audio/audio_input_controller.cc
diff --git a/media/audio/audio_input_controller.cc b/media/audio/audio_input_controller.cc
index c49cb34f342a90baf88fa0eac38b70886db84486..b6f58755dee4c127ca146812c7123c41abe9ed8f 100644
--- a/media/audio/audio_input_controller.cc
+++ b/media/audio/audio_input_controller.cc
@@ -74,11 +74,13 @@ namespace media {
 // static
 AudioInputController::Factory* AudioInputController::factory_ = NULL;
 
-AudioInputController::AudioInputController(EventHandler* handler,
+AudioInputController::AudioInputController(AudioManager* audio_manager,
+                                           EventHandler* handler,
                                            SyncWriter* sync_writer,
                                            UserInputMonitor* user_input_monitor)
     : creator_task_runner_(base::MessageLoopProxy::current()),
       handler_(handler),
+      audio_manager_(audio_manager),
       stream_(NULL),
       data_is_active_(false),
       state_(CLOSED),
@@ -113,16 +115,19 @@ scoped_refptr<AudioInputController> AudioInputController::Create(
     return factory_->Create(
         audio_manager, event_handler, params, user_input_monitor);
   }
-  scoped_refptr<AudioInputController> controller(
-      new AudioInputController(event_handler, NULL, user_input_monitor));
+  scoped_refptr<AudioInputController> controller(new AudioInputController(
+      audio_manager, event_handler, NULL, user_input_monitor));
 
   controller->task_runner_ = audio_manager->GetTaskRunner();
 
   // Create and open a new audio input stream from the existing
   // audio-device thread.
-  if (!controller->task_runner_->PostTask(FROM_HERE,
-          base::Bind(&AudioInputController::DoCreate, controller,
-                     base::Unretained(audio_manager), params, device_id))) {
+  if (!controller->task_runner_->PostTask(
+          FROM_HERE,
+          base::Bind(&AudioInputController::DoCreate,
+                     controller,
+                     params,
+                     device_id))) {
     controller = NULL;
   }
 
@@ -145,15 +150,18 @@ scoped_refptr<AudioInputController> AudioInputController::CreateLowLatency(
 
   // Create the AudioInputController object and ensure that it runs on
   // the audio-manager thread.
-  scoped_refptr<AudioInputController> controller(
-      new AudioInputController(event_handler, sync_writer, user_input_monitor));
+  scoped_refptr<AudioInputController> controller(new AudioInputController(
+      audio_manager, event_handler, sync_writer, user_input_monitor));
   controller->task_runner_ = audio_manager->GetTaskRunner();
 
   // Create and open a new audio input stream from the existing
   // audio-device thread. Use the provided audio-input device.
-  if (!controller->task_runner_->PostTask(FROM_HERE,
-          base::Bind(&AudioInputController::DoCreateForLowLatency, controller,
-                     base::Unretained(audio_manager), params, device_id))) {
+  if (!controller->task_runner_->PostTask(
+          FROM_HERE,
+          base::Bind(&AudioInputController::DoCreate,
+                     controller,
+                     params,
+                     device_id))) {
     controller = NULL;
   }
 
@@ -172,8 +180,8 @@ scoped_refptr<AudioInputController> AudioInputController::CreateForStream(
 
   // Create the AudioInputController object and ensure that it runs on
   // the audio-manager thread.
-  scoped_refptr<AudioInputController> controller(
-      new AudioInputController(event_handler, sync_writer, user_input_monitor));
+  scoped_refptr<AudioInputController> controller(new AudioInputController(
+      NULL, event_handler, sync_writer, user_input_monitor));
   controller->task_runner_ = task_runner;
 
   // TODO(miu): See TODO at top of file.  Until that's resolved, we need to
@@ -215,11 +223,13 @@ void AudioInputController::SetAutomaticGainControl(bool enabled) {
       &AudioInputController::DoSetAutomaticGainControl, this, enabled));
 }
 
-void AudioInputController::DoCreate(AudioManager* audio_manager,
-                                    const AudioParameters& params,
+void AudioInputController::DoCreate(const AudioParameters& params,
                                     const std::string& device_id) {
   DCHECK(task_runner_->BelongsToCurrentThread());
   SCOPED_UMA_HISTOGRAM_TIMER("Media.AudioInputController.CreateTime");
+  if (handler_) {
+    handler_->OnLog(this, "AIC::DoCreate()");
+  }
 
 #if defined(AUDIO_POWER_MONITORING)
   // Create the audio (power) level meter given the provided audio parameters.
@@ -233,26 +243,14 @@ void AudioInputController::DoCreate(AudioManager* audio_manager,
   silence_state_ = SILENCE_STATE_NO_MEASUREMENT;
 #endif
 
+  if (audio_manager_)
+    audio_manager_->AddStateChangeListener(this);
+
   // TODO(miu): See TODO at top of file.  Until that's resolved, assume all
   // platform audio input requires the |no_data_timer_| be used to auto-detect
   // errors.  In reality, probably only Windows needs to be treated as
   // unreliable here.
-  DoCreateForStream(audio_manager->MakeAudioInputStream(params, device_id));
-}
-
-void AudioInputController::DoCreateForLowLatency(AudioManager* audio_manager,
-                                                 const AudioParameters& params,
-                                                 const std::string& device_id) {
-  DCHECK(task_runner_->BelongsToCurrentThread());
-
-#if defined(AUDIO_POWER_MONITORING)
-  // We only log silence state UMA stats for low latency mode and if we use a
-  // real device.
-  if (params.format() != AudioParameters::AUDIO_FAKE)
-    log_silence_state_ = true;
-#endif
-
-  DoCreate(audio_manager, params, device_id);
+  DoCreateForStream(audio_manager_->MakeAudioInputStream(params, device_id));
 }
 
 void AudioInputController::DoCreateForStream(
@@ -315,6 +313,9 @@ void AudioInputController::DoRecord() {
     state_ = RECORDING;
   }
 
+  if (handler_)
+    handler_->OnLog(this, "AIC::DoRecord");
+
   if (no_data_timer_) {
     // Start the data timer. Once |kTimerResetIntervalSeconds| have passed,
     // a callback to FirstCheckForNoData() is made.
@@ -333,12 +334,18 @@ void AudioInputController::DoClose() {
   if (state_ == CLOSED)
     return;
 
+  if (handler_)
+    handler_->OnLog(this, "AIC::DoClose");
+
   // Delete the timer on the same thread that created it.
   no_data_timer_.reset();
 
   DoStopCloseAndClearStream();
   SetDataIsActive(false);
 
+  if (audio_manager_)
+    audio_manager_->RemoveStateChangeListener(this);
+
   if (SharedMemoryAndSyncSocketMode())
     sync_writer_->Close();
 
@@ -400,6 +407,12 @@ void AudioInputController::FirstCheckForNoData() {
   LogCaptureStartupResult(GetDataIsActive() ?
                           CAPTURE_STARTUP_OK :
                           CAPTURE_STARTUP_NO_DATA_CALLBACK);
+  if (handler_) {
+    GetDataIsActive()

[tommi (sloooow) - chröme, 2014/08/26 11:42:30]

instead of having two call sites for OnLog, do the ?: check inside the call to
OnLog:

handler_->OnLog(this, GetDataIsActive() : "string1" : "string2");

[henrika (OOO until Aug 14), 2014/08/27 13:44:05]

Done.

+        ? handler_->OnLog(this, "AIC::FirstCheckForNoData => data is active")
+        : handler_->OnLog(this,
+                          "AIC::FirstCheckForNoData => data is NOT active");
+  }
   DoCheckForNoData();
 }
 
@@ -528,6 +541,12 @@ void AudioInputController::DoLogAudioLevel(float level_dbfs) {
 #endif
 }
 
+void AudioInputController::OnStateChange(const std::string& state) {
+  DCHECK(task_runner_->BelongsToCurrentThread());
+  if (handler_)
+    handler_->OnLog(this, state);
+}
+
 void AudioInputController::OnError(AudioInputStream* stream) {
   // Handle error on the audio-manager thread.
   task_runner_->PostTask(FROM_HERE, base::Bind(