Improve tone and audio mode logging in Telecom.
Add a local log to CallAudioModeStateMachine to log state changes and
audio mode changes which take place.
Add missing audio mode change logs for unfocused state.
Improve logging in InCallTonePlayer to make it more clear when tone
termination is going to trigger a mode change in CAMSM.
Test: Make calls and verify that the telecom dumpsys now logs the audio
mode state transitions, as well as audio mode changes.
Test: Inspect Telecom dumpsys logs for clarity of InCallTonePlayer logs.
Bug: 224688012
Change-Id: I4a1f264053d6557b54143c67d920aa5a12eaa075
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());