From 74a5596a8aeb4c112a6c024e9613d58ba662a5b5 Mon Sep 17 00:00:00 2001 From: Jean-Michel Trivi Date: Mon, 2 Oct 2017 17:46:18 -0700 Subject: [PATCH] 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 --- .../server/audio/AudioEventLogger.java | 18 ++++++ .../server/audio/PlaybackActivityMonitor.java | 55 +++++++++++++------ 2 files changed, 57 insertions(+), 16 deletions(-) diff --git a/services/core/java/com/android/server/audio/AudioEventLogger.java b/services/core/java/com/android/server/audio/AudioEventLogger.java index c96138fff8e6f..a2c0f76bd8416 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; @@ -46,6 +48,22 @@ public class AudioEventLogger { .append(" ").append(eventToString()).toString(); } + /** + * 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: + * 
+         *     myLogger.log(
+         *         (new StringEvent("something for logcat and logger")).printLog(MyClass.TAG) );
+         *
+ * @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, diff --git a/services/core/java/com/android/server/audio/PlaybackActivityMonitor.java b/services/core/java/com/android/server/audio/PlaybackActivityMonitor.java index d1a37af5e7a8d..9195a9ba33b4b 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 @@ public final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor 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 final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor } pw.println("\n"); // log - mEventLogger.dump(pw); + sEventLogger.dump(pw); } } @@ -456,7 +456,8 @@ public final class PlaybackActivityMonitor } 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 @@ public final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor 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 @@ public final class PlaybackActivityMonitor } } - 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 @@ public final class PlaybackActivityMonitor } } - private final AudioEventLogger mEventLogger = new AudioEventLogger(100, + private static final AudioEventLogger sEventLogger = new AudioEventLogger(100, "playback activity as reported through PlayerBase"); }