Merge "Improve tone and audio mode logging in Telecom." into tm-dev
diff --git a/src/com/android/server/telecom/CallAudioManager.java b/src/com/android/server/telecom/CallAudioManager.java
index 6a7261e..6a1f5aa 100644
--- a/src/com/android/server/telecom/CallAudioManager.java
+++ b/src/com/android/server/telecom/CallAudioManager.java
@@ -537,9 +537,9 @@
         pw.println("Foreground call:");
         pw.println(mForegroundCall);
 
-        pw.println("CallAudioModeStateMachine pending messages:");
+        pw.println("CallAudioModeStateMachine:");
         pw.increaseIndent();
-        mCallAudioModeStateMachine.dumpPendingMessages(pw);
+        mCallAudioModeStateMachine.dump(pw);
         pw.decreaseIndent();
 
         pw.println("CallAudioRouteStateMachine pending messages:");
@@ -557,6 +557,7 @@
 
     @VisibleForTesting
     public void setIsTonePlaying(boolean isTonePlaying) {
+        Log.i(this, "setIsTonePlaying; isTonePlaying=%b", isTonePlaying);
         mIsTonePlaying = isTonePlaying;
         mCallAudioModeStateMachine.sendMessageWithArgs(
                 isTonePlaying ? CallAudioModeStateMachine.TONE_STARTED_PLAYING
diff --git a/src/com/android/server/telecom/CallAudioModeStateMachine.java b/src/com/android/server/telecom/CallAudioModeStateMachine.java
index 2aa9d5d..a1c5f4b 100644
--- a/src/com/android/server/telecom/CallAudioModeStateMachine.java
+++ b/src/com/android/server/telecom/CallAudioModeStateMachine.java
@@ -22,6 +22,7 @@
 import android.telecom.Log;
 import android.telecom.Logging.Runnable;
 import android.telecom.Logging.Session;
+import android.util.LocalLog;
 import android.util.SparseArray;
 
 import com.android.internal.util.IState;
@@ -30,6 +31,11 @@
 import com.android.internal.util.StateMachine;
 
 public class CallAudioModeStateMachine extends StateMachine {
+    /**
+     * Captures the most recent CallAudioModeStateMachine state transitions and the corresponding
+     * changes to the {@link AudioManager#setMode}.
+     */
+    private LocalLog mLocalLog = new LocalLog(20);
     public static class Factory {
         public CallAudioModeStateMachine create(SystemStateHelper systemStateHelper,
                 AudioManager am) {
@@ -227,9 +233,12 @@
     private class UnfocusedState extends BaseState {
         @Override
         public void enter() {
+            Log.i(LOG_TAG, "Audio focus entering UNFOCUSED state");
+            mLocalLog.log("Enter UNFOCUSED");
             if (mIsInitialized) {
                 mCallAudioManager.setCallAudioRouteFocusState(CallAudioRouteStateMachine.NO_FOCUS);
                 mAudioManager.setMode(AudioManager.MODE_NORMAL);
+                mLocalLog.log("Mode MODE_NORMAL");
                 mMostRecentMode = AudioManager.MODE_NORMAL;
                 // Don't release focus here -- wait until we get a signal that any other audio
                 // operations triggered by this are done before releasing focus.
@@ -290,9 +299,12 @@
     private class AudioProcessingFocusState extends BaseState {
         @Override
         public void enter() {
+            Log.i(LOG_TAG, "Audio focus entering AUDIO_PROCESSING state");
+            mLocalLog.log("Enter AUDIO_PROCESSING");
             if (mIsInitialized) {
                 mCallAudioManager.setCallAudioRouteFocusState(CallAudioRouteStateMachine.NO_FOCUS);
                 mAudioManager.setMode(NEW_AUDIO_MODE_FOR_AUDIO_PROCESSING);
+                mLocalLog.log("Mode MODE_CALL_SCREENING");
                 mMostRecentMode = NEW_AUDIO_MODE_FOR_AUDIO_PROCESSING;
             }
         }
@@ -371,6 +383,7 @@
                 // trips up the audio system.
                 if (mAudioManager.getMode() != AudioManager.MODE_CALL_SCREENING) {
                     mAudioManager.setMode(AudioManager.MODE_RINGTONE);
+                    mLocalLog.log("Mode MODE_RINGTONE");
                 }
                 mCallAudioManager.setCallAudioRouteFocusState(
                         CallAudioRouteStateMachine.RINGING_FOCUS);
@@ -383,6 +396,7 @@
         @Override
         public void enter() {
             Log.i(LOG_TAG, "Audio focus entering RINGING state");
+            mLocalLog.log("Enter RINGING");
             tryStartRinging();
             mCallAudioManager.stopCallWaiting();
         }
@@ -456,9 +470,11 @@
         @Override
         public void enter() {
             Log.i(LOG_TAG, "Audio focus entering SIM CALL state");
+            mLocalLog.log("Enter SIM_CALL");
             mAudioManager.requestAudioFocusForCall(AudioManager.STREAM_VOICE_CALL,
                     AudioManager.AUDIOFOCUS_GAIN_TRANSIENT);
             mAudioManager.setMode(AudioManager.MODE_IN_CALL);
+            mLocalLog.log("Mode MODE_IN_CALL");
             mMostRecentMode = AudioManager.MODE_IN_CALL;
             mCallAudioManager.setCallAudioRouteFocusState(CallAudioRouteStateMachine.ACTIVE_FOCUS);
         }
@@ -537,9 +553,11 @@
         @Override
         public void enter() {
             Log.i(LOG_TAG, "Audio focus entering VOIP CALL state");
+            mLocalLog.log("Enter VOIP_CALL");
             mAudioManager.requestAudioFocusForCall(AudioManager.STREAM_VOICE_CALL,
                     AudioManager.AUDIOFOCUS_GAIN_TRANSIENT);
             mAudioManager.setMode(AudioManager.MODE_IN_COMMUNICATION);
+            mLocalLog.log("Mode MODE_IN_COMMUNICATION");
             mMostRecentMode = AudioManager.MODE_IN_COMMUNICATION;
             mCallAudioManager.setCallAudioRouteFocusState(CallAudioRouteStateMachine.ACTIVE_FOCUS);
         }
@@ -614,9 +632,11 @@
         @Override
         public void enter() {
             Log.i(LOG_TAG, "Audio focus entering TONE/HOLDING state");
+            mLocalLog.log("Enter TONE/HOLDING");
             mAudioManager.requestAudioFocusForCall(AudioManager.STREAM_VOICE_CALL,
                     AudioManager.AUDIOFOCUS_GAIN_TRANSIENT);
             mAudioManager.setMode(mMostRecentMode);
+            mLocalLog.log("Mode " + mMostRecentMode);
             mCallAudioManager.setCallAudioRouteFocusState(CallAudioRouteStateMachine.ACTIVE_FOCUS);
         }
 
@@ -763,6 +783,13 @@
         getHandler().getLooper().dump(pw::println, "");
     }
 
+    public void dump(IndentingPrintWriter pw) {
+        pw.println("History:");
+        mLocalLog.dump(pw);
+        pw.println("Pending Msg:");
+        dumpPendingMessages(pw);
+    }
+
     @Override
     protected void onPostHandleMessage(Message msg) {
         Log.endSession();
diff --git a/src/com/android/server/telecom/InCallTonePlayer.java b/src/com/android/server/telecom/InCallTonePlayer.java
index 524d119..5a514ce 100644
--- a/src/com/android/server/telecom/InCallTonePlayer.java
+++ b/src/com/android/server/telecom/InCallTonePlayer.java
@@ -438,7 +438,8 @@
             mToneMediaPlayer.setOnCompletionListener(new MediaPlayer.OnCompletionListener() {
                 @Override
                 public void onCompletion(MediaPlayer mp) {
-                    Log.i(this, "playMediaTone: toneResourceId=%d completed.", toneResourceId);
+                    Log.i(InCallTonePlayer.this, "playMediaTone: toneResourceId=%d completed.",
+                            toneResourceId);
                     synchronized (InCallTonePlayer.this) {
                         mState = STATE_OFF;
                     }
@@ -508,14 +509,26 @@
     }
 
     private void cleanUpTonePlayer() {
+        Log.d(this, "cleanUpTonePlayer(): posting cleanup");
         // Release focus on the main thread.
         mMainThreadHandler.post(new Runnable("ICTP.cUTP", mLock) {
             @Override
             public void loggedRun() {
                 if (sTonesPlaying == 0) {
-                    Log.wtf(this, "Over-releasing focus for tone player.");
-                } else if (--sTonesPlaying == 0 && mCallAudioManager != null) {
-                    mCallAudioManager.setIsTonePlaying(false);
+                    Log.wtf(InCallTonePlayer.this,
+                            "cleanUpTonePlayer(): Over-releasing focus for tone player.");
+                } else if (--sTonesPlaying == 0) {
+                    Log.i(InCallTonePlayer.this,
+                            "cleanUpTonePlayer(): tonesPlaying=%d, tone completed", sTonesPlaying);
+                    if (mCallAudioManager != null) {
+                        mCallAudioManager.setIsTonePlaying(false);
+                    } else {
+                        Log.w(InCallTonePlayer.this,
+                                "cleanUpTonePlayer(): mCallAudioManager is null!");
+                    }
+                } else {
+                    Log.i(InCallTonePlayer.this,
+                            "cleanUpTonePlayer(): tonesPlaying=%d; still playing", sTonesPlaying);
                 }
             }
         }.prepare());