AudioService: log ducking and incall muting of audio players
Event logger: add support for logging the text of the event in
the logcat at the same time to avoid having the duplicate the
logcat entry and the logger event. See printLog() method.
AudioPlaybackMonitor: log ducking and incall muting.
Test: play media and notification, verify logs appear in logcat and dumpsys audio
Bug:65363602
Change-Id: I2af0c2bbd2fde428f07761ca45e7950a16843604
diff --git a/services/core/java/com/android/server/audio/AudioEventLogger.java b/services/core/java/com/android/server/audio/AudioEventLogger.java
index c96138f..a2c0f76 100644
--- a/services/core/java/com/android/server/audio/AudioEventLogger.java
+++ b/services/core/java/com/android/server/audio/AudioEventLogger.java
@@ -16,6 +16,8 @@
package com.android.server.audio;
+import android.util.Log;
+
import java.io.PrintWriter;
import java.text.SimpleDateFormat;
import java.util.Date;
@@ -47,6 +49,22 @@
}
/**
+ * Causes the string message for the event to appear in the verbose logcat.
+ * Here is an example of how to create a new event (a StringEvent), adding it to the logger
+ * (an instance of AudioEventLogger) while also making it show in the verbose logcat:
+ * <pre>
+ * myLogger.log(
+ * (new StringEvent("something for logcat and logger")).printLog(MyClass.TAG) );
+ * </pre>
+ * @param tag the tag for the android.util.Log.v
+ * @return the same instance of the event
+ */
+ public Event printLog(String tag) {
+ Log.v(tag, eventToString());
+ return this;
+ }
+
+ /**
* Convert event to String.
* This method is only called when the logger history is about to the dumped,
* so this method is where expensive String conversions should be made, not when the Event
diff --git a/services/core/java/com/android/server/audio/PlaybackActivityMonitor.java b/services/core/java/com/android/server/audio/PlaybackActivityMonitor.java
index d1a37af..9195a9b 100644
--- a/services/core/java/com/android/server/audio/PlaybackActivityMonitor.java
+++ b/services/core/java/com/android/server/audio/PlaybackActivityMonitor.java
@@ -105,7 +105,7 @@
if (index >= 0) {
if (!disable) {
if (DEBUG) { // hidden behind DEBUG, too noisy otherwise
- mEventLogger.log(new AudioEventLogger.StringEvent("unbanning uid:" + uid));
+ sEventLogger.log(new AudioEventLogger.StringEvent("unbanning uid:" + uid));
}
mBannedUids.remove(index);
// nothing else to do, future playback requests from this uid are ok
@@ -116,7 +116,7 @@
checkBanPlayer(apc, uid);
}
if (DEBUG) { // hidden behind DEBUG, too noisy otherwise
- mEventLogger.log(new AudioEventLogger.StringEvent("banning uid:" + uid));
+ sEventLogger.log(new AudioEventLogger.StringEvent("banning uid:" + uid));
}
mBannedUids.add(new Integer(uid));
} // no else to handle, uid already not in list, so enabling again is no-op
@@ -151,7 +151,7 @@
new AudioPlaybackConfiguration(pic, newPiid,
Binder.getCallingUid(), Binder.getCallingPid());
apc.init();
- mEventLogger.log(new NewPlayerEvent(apc));
+ sEventLogger.log(new NewPlayerEvent(apc));
synchronized(mPlayerLock) {
mPlayers.put(newPiid, apc);
}
@@ -163,7 +163,7 @@
synchronized(mPlayerLock) {
final AudioPlaybackConfiguration apc = mPlayers.get(new Integer(piid));
if (checkConfigurationCaller(piid, apc, binderUid)) {
- mEventLogger.log(new AudioAttrEvent(piid, attr));
+ sEventLogger.log(new AudioAttrEvent(piid, attr));
change = apc.handleAudioAttributesEvent(attr);
} else {
Log.e(TAG, "Error updating audio attributes");
@@ -183,12 +183,12 @@
if (apc == null) {
return;
}
- mEventLogger.log(new PlayerEvent(piid, event));
+ sEventLogger.log(new PlayerEvent(piid, event));
if (event == AudioPlaybackConfiguration.PLAYER_STATE_STARTED) {
for (Integer uidInteger: mBannedUids) {
if (checkBanPlayer(apc, uidInteger.intValue())) {
// player was banned, do not update its state
- mEventLogger.log(new AudioEventLogger.StringEvent(
+ sEventLogger.log(new AudioEventLogger.StringEvent(
"not starting piid:" + piid + " ,is banned"));
return;
}
@@ -216,7 +216,7 @@
public void playerHasOpPlayAudio(int piid, boolean hasOpPlayAudio, int binderUid) {
// no check on UID yet because this is only for logging at the moment
- mEventLogger.log(new PlayerOpPlayAudioEvent(piid, hasOpPlayAudio, binderUid));
+ sEventLogger.log(new PlayerOpPlayAudioEvent(piid, hasOpPlayAudio, binderUid));
}
public void releasePlayer(int piid, int binderUid) {
@@ -224,7 +224,7 @@
synchronized(mPlayerLock) {
final AudioPlaybackConfiguration apc = mPlayers.get(new Integer(piid));
if (checkConfigurationCaller(piid, apc, binderUid)) {
- mEventLogger.log(new AudioEventLogger.StringEvent(
+ sEventLogger.log(new AudioEventLogger.StringEvent(
"releasing player piid:" + piid));
mPlayers.remove(new Integer(piid));
mDuckingManager.removeReleased(apc);
@@ -278,7 +278,7 @@
}
pw.println("\n");
// log
- mEventLogger.dump(pw);
+ sEventLogger.dump(pw);
}
}
@@ -456,7 +456,8 @@
}
if (mute) {
try {
- Log.v(TAG, "call: muting player" + piid + " uid:" + apc.getClientUid());
+ sEventLogger.log((new AudioEventLogger.StringEvent("call: muting piid:"
+ + piid + " uid:" + apc.getClientUid())).printLog(TAG));
apc.getPlayerProxy().setVolume(0.0f);
mMutedPlayers.add(new Integer(piid));
} catch (Exception e) {
@@ -480,7 +481,8 @@
final AudioPlaybackConfiguration apc = mPlayers.get(piid);
if (apc != null) {
try {
- Log.v(TAG, "call: unmuting player" + piid + " uid:" + apc.getClientUid());
+ sEventLogger.log(new AudioEventLogger.StringEvent("call: unmuting piid:"
+ + piid).printLog(TAG));
apc.getPlayerProxy().setVolume(1.0f);
} catch (Exception e) {
Log.e(TAG, "call: error unmuting player " + piid + " uid:"
@@ -669,8 +671,7 @@
return;
}
try {
- Log.v(TAG, "ducking (skipRamp=" + skipRamp + ") player piid:"
- + apc.getPlayerInterfaceId() + " uid:" + mUid);
+ sEventLogger.log((new DuckEvent(apc, skipRamp)).printLog(TAG));
apc.getPlayerProxy().applyVolumeShaper(
DUCK_VSHAPE,
skipRamp ? PLAY_SKIP_RAMP : PLAY_CREATE_IF_NEEDED);
@@ -685,7 +686,8 @@
final AudioPlaybackConfiguration apc = players.get(piid);
if (apc != null) {
try {
- Log.v(TAG, "unducking player " + piid + " uid:" + mUid);
+ sEventLogger.log((new AudioEventLogger.StringEvent("unducking piid:"
+ + piid)).printLog(TAG));
apc.getPlayerProxy().applyVolumeShaper(
DUCK_ID,
VolumeShaper.Operation.REVERSE);
@@ -772,7 +774,28 @@
}
}
- private final static class AudioAttrEvent extends AudioEventLogger.Event {
+ private static final class DuckEvent extends AudioEventLogger.Event {
+ private final int mPlayerIId;
+ private final boolean mSkipRamp;
+ private final int mClientUid;
+ private final int mClientPid;
+
+ DuckEvent(@NonNull AudioPlaybackConfiguration apc, boolean skipRamp) {
+ mPlayerIId = apc.getPlayerInterfaceId();
+ mSkipRamp = skipRamp;
+ mClientUid = apc.getClientUid();
+ mClientPid = apc.getClientPid();
+ }
+
+ @Override
+ public String eventToString() {
+ return new StringBuilder("ducking player piid:").append(mPlayerIId)
+ .append(" uid/pid:").append(mClientUid).append("/").append(mClientPid)
+ .append(" skip ramp:").append(mSkipRamp).toString();
+ }
+ }
+
+ private static final class AudioAttrEvent extends AudioEventLogger.Event {
private final int mPlayerIId;
private final AudioAttributes mPlayerAttr;
@@ -787,6 +810,6 @@
}
}
- private final AudioEventLogger mEventLogger = new AudioEventLogger(100,
+ private static final AudioEventLogger sEventLogger = new AudioEventLogger(100,
"playback activity as reported through PlayerBase");
}