Add additional audio focus logging (9159b6ca) · Commits · e / os / android_frameworks_base

services/core/java/com/android/server/audio/FocusRequester.java

+111 −61

Original line number	Diff line number	Diff line
		@@ -16,6 +16,9 @@

		package com.android.server.audio;

		import static com.android.server.utils.EventLogger.Event.ALOGE;
		import static com.android.server.utils.EventLogger.Event.ALOGW;

		import android.annotation.NonNull;
		import android.annotation.Nullable;
		import android.content.pm.UserProperties;
		@@ -24,6 +27,7 @@ import android.media.AudioFocusInfo;
		import android.media.AudioManager;
		import android.media.IAudioFocusDispatcher;
		import android.os.IBinder;
		import android.os.RemoteException;
		import android.os.UserHandle;
		import android.util.Log;

		@@ -31,6 +35,7 @@ import com.android.internal.annotations.GuardedBy;
		import com.android.server.LocalServices;
		import com.android.server.audio.MediaFocusControl.AudioFocusDeathHandler;
		import com.android.server.pm.UserManagerInternal;
		import com.android.server.utils.EventLogger;

		import java.io.PrintWriter;
		import java.util.List;
		@@ -84,6 +89,8 @@ public class FocusRequester {
		*/
		private final @NonNull AudioAttributes mAttributes;

		private final EventLogger mEventLogger;

		/**
		* Class constructor
		* @param aa
		@@ -100,7 +107,7 @@ public class FocusRequester {
		FocusRequester(@NonNull AudioAttributes aa, int focusRequest, int grantFlags,
		IAudioFocusDispatcher afl, IBinder source, @NonNull String id,
		AudioFocusDeathHandler hdlr, @NonNull String pn, int uid,
		@NonNull MediaFocusControl ctlr, int sdk) {
		@NonNull MediaFocusControl ctlr, int sdk, EventLogger eventLogger) {
		mAttributes = aa;
		mFocusDispatcher = afl;
		mSourceRef = source;
		@@ -115,10 +122,12 @@ public class FocusRequester {
		mFocusLossFadeLimbo = false;
		mFocusController = ctlr;
		mSdkTarget = sdk;
		mEventLogger = eventLogger;
		}

		FocusRequester(AudioFocusInfo afi, IAudioFocusDispatcher afl,
		IBinder source, AudioFocusDeathHandler hdlr, @NonNull MediaFocusControl ctlr) {
		IBinder source, AudioFocusDeathHandler hdlr, @NonNull MediaFocusControl ctlr,
		EventLogger eventLogger) {
		mAttributes = afi.getAttributes();
		mClientId = afi.getClientId();
		mPackageName = afi.getPackageName();
		@@ -134,6 +143,7 @@ public class FocusRequester {
		mSourceRef = source;
		mDeathHandler = hdlr;
		mFocusController = ctlr;
		mEventLogger = eventLogger;
		}

		boolean hasSameClient(String otherClient) {
		@@ -357,18 +367,22 @@ public class FocusRequester {
		mFocusController.notifyExtPolicyFocusGrant_syncAf(toAudioFocusInfo(),
		AudioManager.AUDIOFOCUS_REQUEST_GRANTED);
		final IAudioFocusDispatcher fd = mFocusDispatcher;
		if (fd != null) {
		if (fd != null && mFocusLossWasNotified) {
		if (DEBUG) {
		Log.v(TAG, "dispatching " + focusChangeToString(focusGain) + " to "
		+ mClientId);
		}
		if (mFocusLossWasNotified) {
		fd.dispatchAudioFocusChange(focusGain, mClientId);
		}
		mEventLogger.enqueue(new FocusRequestEvent(
		this, focusGain, "handleGain"));
		} else if (mFocusLossWasNotified) {
		mEventLogger.enqueue(new FocusRequestEvent(
		this, focusGain, "handleGain no listener").printSlog(ALOGW, TAG));
		}
		mFocusController.restoreVShapedPlayers(this);
		} catch (android.os.RemoteException e) {
		Log.e(TAG, "Failure to signal gain of audio focus due to: ", e);
		} catch (RemoteException e) {
		mEventLogger.enqueue(new FocusRequestEvent(
		this, focusGain, "handleGain exc: " + e).printSlog(ALOGE, TAG));
		}
		}

		@@ -385,7 +399,6 @@ public class FocusRequester {
		if (DEBUG) {
		Log.i(TAG, "handleFocusLoss for " + mClientId + " loss:" + focusLoss);
		}
		try {
		if (focusLoss != mFocusLossReceived) {
		mFocusLossReceived = focusLoss;
		mFocusLossWasNotified = false;
		@@ -433,14 +446,20 @@ public class FocusRequester {
		mFocusController.notifyExtPolicyFocusLoss_syncAf(
		toAudioFocusInfo(), true /* wasDispatched */);
		mFocusLossWasNotified = true;
		try {
		fd.dispatchAudioFocusChange(mFocusLossReceived, mClientId);
		} else if (DEBUG) {
		Log.i(TAG, "NOT dispatching " + focusChangeToString(mFocusLossReceived)
		+ " to " + mClientId + " no IAudioFocusDispatcher");
		mEventLogger.enqueue(new FocusRequestEvent(
		this, mFocusLossReceived, "handleLoss"));
		} catch (RemoteException e) {
		mEventLogger.enqueue(new FocusRequestEvent(
		this, mFocusLossReceived, "handleLoss failed exc: " + e)
		.printSlog(ALOGE,TAG));
		}
		} else {
		mEventLogger.enqueue(new FocusRequestEvent(
		this, mFocusLossReceived, "handleLoss failed no listener")
		.printSlog(ALOGE, TAG));
		}
		} catch (android.os.RemoteException e) {
		Log.e(TAG, "Failure to signal loss of audio focus due to:", e);
		}
		}

		@@ -505,7 +524,7 @@ public class FocusRequester {
		return false;
		}

		int dispatchFocusChange(int focusChange) {
		int dispatchFocusChange(int focusChange, String reason) {
		final IAudioFocusDispatcher fd = mFocusDispatcher;
		if (fd == null) {
		if (MediaFocusControl.DEBUG) { Log.e(TAG, "dispatchFocusChange: no focus dispatcher"); }
		@@ -528,8 +547,11 @@ public class FocusRequester {
		}
		try {
		fd.dispatchAudioFocusChange(focusChange, mClientId);
		} catch (android.os.RemoteException e) {
		Log.e(TAG, "dispatchFocusChange: error talking to focus listener " + mClientId, e);
		mEventLogger.enqueue(new FocusRequestEvent(this,
		focusChange, "dispatch: " + reason));
		} catch (RemoteException e) {
		mEventLogger.enqueue(new FocusRequestEvent(
		this, focusChange, "dispatch failed: " + e).printSlog(ALOGE, TAG));
		return AudioManager.AUDIOFOCUS_REQUEST_FAILED;
		}
		return AudioManager.AUDIOFOCUS_REQUEST_GRANTED;
		@@ -559,7 +581,7 @@ public class FocusRequester {
		}
		}
		}
		return dispatchFocusChange(focusChange);
		return dispatchFocusChange(focusChange, "focus with fade");
		}

		void dispatchFocusResultFromExtPolicy(int requestResult) {
		@@ -575,7 +597,7 @@ public class FocusRequester {
		}
		try {
		fd.dispatchFocusResultFromExtPolicy(requestResult, mClientId);
		} catch (android.os.RemoteException e) {
		} catch (RemoteException e) {
		Log.e(TAG, "dispatchFocusResultFromExtPolicy: error talking to focus listener"
		+ mClientId, e);
		}
		@@ -585,4 +607,32 @@ public class FocusRequester {
		return new AudioFocusInfo(mAttributes, mCallingUid, mClientId, mPackageName,
		mFocusGainRequest, mFocusLossReceived, mGrantFlags, mSdkTarget);
		}

		static class FocusRequestEvent extends EventLogger.Event {
		private final String mClientId;
		private final int mUid;
		private final String mPackageName;
		private final int mCode;
		private final String mDescription;

		public FocusRequestEvent(FocusRequester fr, String description) {
		this(fr, -1, description);
		}

		public FocusRequestEvent(FocusRequester fr, int code, String description) {
		mClientId = fr.getClientId();
		mUid = fr.getClientUid();
		mPackageName = fr.getPackageName();
		mCode = code;
		mDescription = description != null ? description : "";
		}
		@Override
		public String eventToString() {
		return "focus owner: " + mClientId + " in uid: " + mUid
		+ " pack: " + mPackageName
		+ ((mCode != -1) ? " code: " + mCode : "")
		+ " event: " + mDescription;
		}
		}

		}

services/core/java/com/android/server/audio/MediaFocusControl.java

+8 −20

Original line number	Diff line number	Diff line
		@@ -231,13 +231,8 @@ public class MediaFocusControl implements PlayerFocusEnforcer {
		final FocusRequester focusOwner = stackIterator.next();
		if (focusOwner.hasSameUid(uid) && focusOwner.hasSamePackage(packageName)) {
		clientsToRemove.add(focusOwner.getClientId());
		mEventLogger.enqueue((new EventLogger.StringEvent(
		"focus owner:" + focusOwner.getClientId()
		+ " in uid:" + uid + " pack: " + packageName
		+ " getting AUDIOFOCUS_LOSS due to app suspension"))
		.printLog(TAG));
		// make the suspended app lose focus through its focus listener (if any)
		focusOwner.dispatchFocusChange(AudioManager.AUDIOFOCUS_LOSS);
		focusOwner.dispatchFocusChange(AudioManager.AUDIOFOCUS_LOSS, "app suspension");
		}
		}
		for (String clientToRemove : clientsToRemove) {
		@@ -548,11 +543,7 @@ public class MediaFocusControl implements PlayerFocusEnforcer {
		FocusRequester fr = stackIterator.next();
		if(fr.hasSameBinder(cb)) {
		Log.i(TAG, "AudioFocus removeFocusStackEntryOnDeath(): removing entry for " + cb);
		mEventLogger.enqueue(new EventLogger.StringEvent(
		"focus requester:" + fr.getClientId()
		+ " in uid:" + fr.getClientUid()
		+ " pack:" + fr.getPackageName()
		+ " died"));
		mEventLogger.enqueue(new FocusRequester.FocusRequestEvent(fr, " died"));
		notifyExtPolicyFocusLoss_syncAf(fr.toAudioFocusInfo(), false);

		stackIterator.remove();
		@@ -585,11 +576,7 @@ public class MediaFocusControl implements PlayerFocusEnforcer {
		final FocusRequester fr = owner.getValue();
		if (fr.hasSameBinder(cb)) {
		ownerIterator.remove();
		mEventLogger.enqueue(new EventLogger.StringEvent(
		"focus requester:" + fr.getClientId()
		+ " in uid:" + fr.getClientUid()
		+ " pack:" + fr.getPackageName()
		+ " died"));
		mEventLogger.enqueue(new FocusRequester.FocusRequestEvent(fr, "died"));
		fr.release();
		notifyExtFocusPolicyFocusAbandon_syncAf(fr.toAudioFocusInfo());
		break;
		@@ -900,7 +887,7 @@ public class MediaFocusControl implements PlayerFocusEnforcer {
		}
		// new focus (future) focus owner to keep track of
		mFocusOwnersForFocusPolicy.put(afi.getClientId(),
		new FocusRequester(afi, fd, cb, hdlr, this));
		new FocusRequester(afi, fd, cb, hdlr, this, mEventLogger));
		}

		try {
		@@ -972,7 +959,7 @@ public class MediaFocusControl implements PlayerFocusEnforcer {
		}
		return AudioManager.AUDIOFOCUS_REQUEST_FAILED;
		}
		return fr.dispatchFocusChange(focusChange);
		return fr.dispatchFocusChange(focusChange, "audiomanager");
		}
		}

		@@ -1006,6 +993,7 @@ public class MediaFocusControl implements PlayerFocusEnforcer {
		otherActiveFrs.add(otherFr);
		}

		// TODO log
		int status = fr.dispatchFocusChangeWithFadeLocked(focusChange, otherActiveFrs);
		if (status != AudioManager.AUDIOFOCUS_REQUEST_DELAYED
		&& focusChange == AudioManager.AUDIOFOCUS_LOSS) {
		@@ -1260,7 +1248,7 @@ public class MediaFocusControl implements PlayerFocusEnforcer {
		removeFocusStackEntry(clientId, false /* signal /, false /notifyFocusFollowers*/);

		final FocusRequester nfr = new FocusRequester(aa, focusChangeHint, flags, fd, cb,
		clientId, afdh, callingPackageName, uid, this, sdk);
		clientId, afdh, callingPackageName, uid, this, sdk, mEventLogger);

		if (mMultiAudioFocusEnabled
		&& (focusChangeHint == AudioManager.AUDIOFOCUS_GAIN)) {
		@@ -1594,7 +1582,7 @@ public class MediaFocusControl implements PlayerFocusEnforcer {
		synchronized (mAudioFocusLock) {
		final FocusRequester loser = (FocusRequester) msg.obj;
		if (loser.isInFocusLossLimbo()) {
		loser.dispatchFocusChange(AudioManager.AUDIOFOCUS_LOSS);
		loser.dispatchFocusChange(AudioManager.AUDIOFOCUS_LOSS, "loss after fade");
		loser.release();
		postForgetUidLater(loser);
		}

services/tests/servicestests/src/com/android/server/audio/FadeOutManagerTest.java

+5 −1

Original line number	Diff line number	Diff line
		@@ -34,6 +34,8 @@ import androidx.test.core.app.ApplicationProvider;

		import com.google.common.truth.Expect;

		import com.android.server.utils.EventLogger;

		import org.junit.Before;
		import org.junit.Rule;
		import org.junit.Test;
		@@ -67,6 +69,8 @@ public final class FadeOutManagerTest {
		PlayerBase.PlayerIdCard mMockPlayerIdCard;
		@Mock
		AudioPlaybackConfiguration mMockPlaybackConfiguration;
		@Mock
		EventLogger mMockEventLogger;

		@Rule
		public final Expect expect = Expect.create();
		@@ -193,7 +197,7 @@ public final class FadeOutManagerTest {
		String packageName, int uid, int flags) {
		MediaFocusControl mfc = new MediaFocusControl(mContext, null);
		return new FocusRequester(aa, AudioManager.AUDIOFOCUS_GAIN, flags, null, null, clientId,
		null, packageName, uid, mfc, 1);
		null, packageName, uid, mfc, 1, mMockEventLogger);
		}

		private PlayerBase.PlayerIdCard createPlayerIdCard(AudioAttributes aa, int playerType) {