Log the overhead latency of app function requests (f3f0bdd4) · Commits · e / os / android_frameworks_base

core/java/android/app/appfunctions/SafeOneTimeExecuteAppFunctionCallback.java

+23 −5

Original line number	Diff line number	Diff line
		@@ -19,10 +19,12 @@ package android.app.appfunctions;
		import android.annotation.NonNull;
		import android.annotation.Nullable;
		import android.os.RemoteException;
		import android.os.SystemClock;
		import android.util.Log;

		import java.util.Objects;
		import java.util.concurrent.atomic.AtomicBoolean;
		import java.util.concurrent.atomic.AtomicLong;

		/**
		* A wrapper of IExecuteAppFunctionCallback which swallows the {@link RemoteException}. This
		@@ -38,7 +40,10 @@ public class SafeOneTimeExecuteAppFunctionCallback {

		@NonNull private final IExecuteAppFunctionCallback mCallback;

		@Nullable CompletionCallback mCompletionCallback;
		@Nullable
		private final CompletionCallback mCompletionCallback;

		private final AtomicLong mExecutionStartTimeAfterBindMillis = new AtomicLong();

		public SafeOneTimeExecuteAppFunctionCallback(@NonNull IExecuteAppFunctionCallback callback) {
		this(callback, /* completionCallback= */ null);
		@@ -59,7 +64,8 @@ public class SafeOneTimeExecuteAppFunctionCallback {
		try {
		mCallback.onSuccess(result);
		if (mCompletionCallback != null) {
		mCompletionCallback.finalizeOnSuccess(result);
		mCompletionCallback.finalizeOnSuccess(result,
		mExecutionStartTimeAfterBindMillis.get());
		}
		} catch (RemoteException ex) {
		// Failed to notify the other end. Ignore.
		@@ -76,7 +82,8 @@ public class SafeOneTimeExecuteAppFunctionCallback {
		try {
		mCallback.onError(error);
		if (mCompletionCallback != null) {
		mCompletionCallback.finalizeOnError(error);
		mCompletionCallback.finalizeOnError(error,
		mExecutionStartTimeAfterBindMillis.get());
		}
		} catch (RemoteException ex) {
		// Failed to notify the other end. Ignore.
		@@ -92,15 +99,26 @@ public class SafeOneTimeExecuteAppFunctionCallback {
		mOnResultCalled.set(true);
		}

		/**
		* Sets the execution start time of the request. Used to calculate the overhead latency of
		* requests.
		*/
		public void setExecutionStartTimeMillis() {
		if (!mExecutionStartTimeAfterBindMillis.compareAndSet(0, SystemClock.elapsedRealtime())) {
		Log.w(TAG, "Ignore subsequent calls to setExecutionStartTimeMillis()");
		}
		}

		/**
		* Provides a hook to execute additional actions after the {@link IExecuteAppFunctionCallback}
		* has been invoked.
		*/
		public interface CompletionCallback {
		/** Called after {@link IExecuteAppFunctionCallback#onSuccess}. */
		void finalizeOnSuccess(@NonNull ExecuteAppFunctionResponse result);
		void finalizeOnSuccess(@NonNull ExecuteAppFunctionResponse result,
		long executionStartTimeMillis);

		/** Called after {@link IExecuteAppFunctionCallback#onError}. */
		void finalizeOnError(@NonNull AppFunctionException error);
		void finalizeOnError(@NonNull AppFunctionException error, long executionStartTimeMillis);
		}
		}

services/appfunctions/java/com/android/server/appfunctions/AppFunctionManagerServiceImpl.java

+6 −4

Original line number	Diff line number	Diff line
		@@ -159,15 +159,17 @@ public class AppFunctionManagerServiceImpl extends IAppFunctionManager.Stub {
		new SafeOneTimeExecuteAppFunctionCallback.CompletionCallback() {
		@Override
		public void finalizeOnSuccess(
		@NonNull ExecuteAppFunctionResponse result) {
		@NonNull ExecuteAppFunctionResponse result,
		long executionStartTimeMillis) {
		mLoggerWrapper.logAppFunctionSuccess(requestInternal, result,
		callingUid);
		callingUid, executionStartTimeMillis);
		}

		@Override
		public void finalizeOnError(@NonNull AppFunctionException error) {
		public void finalizeOnError(@NonNull AppFunctionException error,
		long executionStartTimeMillis) {
		mLoggerWrapper.logAppFunctionError(requestInternal,
		error.getErrorCode(), callingUid);
		error.getErrorCode(), callingUid, executionStartTimeMillis);
		}
		});

services/appfunctions/java/com/android/server/appfunctions/AppFunctionsLoggerWrapper.java

+19 −10

Original line number	Diff line number	Diff line
		@@ -41,25 +41,34 @@ public class AppFunctionsLoggerWrapper {
		}

		void logAppFunctionSuccess(ExecuteAppFunctionAidlRequest request,
		ExecuteAppFunctionResponse response, int callingUid) {
		ExecuteAppFunctionResponse response, int callingUid, long executionStartTimeMillis) {
		logAppFunctionsRequestReported(request, SUCCESS_RESPONSE_CODE,
		response.getResponseDataSize(), callingUid);
		response.getResponseDataSize(), callingUid, executionStartTimeMillis);
		}

		void logAppFunctionError(ExecuteAppFunctionAidlRequest request, int errorCode, int callingUid) {
		logAppFunctionsRequestReported(request, errorCode, /* responseSizeBytes = */ 0, callingUid);
		void logAppFunctionError(ExecuteAppFunctionAidlRequest request, int errorCode, int callingUid,
		long executionStartTimeMillis) {
		logAppFunctionsRequestReported(request, errorCode, /* responseSizeBytes = */ 0, callingUid,
		executionStartTimeMillis);
		}

		private void logAppFunctionsRequestReported(ExecuteAppFunctionAidlRequest request,
		int errorCode, int responseSizeBytes, int callingUid) {
		final long latency = SystemClock.elapsedRealtime() - request.getRequestTime();
		int errorCode, int responseSizeBytes, int callingUid, long executionStartTimeMillis) {
		final long e2eRequestLatencyMillis =
		SystemClock.elapsedRealtime() - request.getRequestTime();
		final long requestOverheadMillis =
		executionStartTimeMillis > 0 ? (executionStartTimeMillis - request.getRequestTime())
		: e2eRequestLatencyMillis;
		LOGGING_THREAD_EXECUTOR.execute(() -> AppFunctionsStatsLog.write(
		AppFunctionsStatsLog.APP_FUNCTIONS_REQUEST_REPORTED,
		callingUid,
		/* callerPackageUid= */ callingUid,
		/* targetPackageUid= */
		getPackageUid(request.getClientRequest().getTargetPackageName()),
		errorCode,
		request.getClientRequest().getRequestDataSize(), responseSizeBytes,
		latency)
		/* errorCode= */ errorCode,
		/* requestSizeBytes= */ request.getClientRequest().getRequestDataSize(),
		/* responseSizeBytes= */ responseSizeBytes,
		/* requestDurationMs= */ e2eRequestLatencyMillis,
		/* requestOverheadMs= */ requestOverheadMillis)
		);
		}

services/appfunctions/java/com/android/server/appfunctions/RunAppFunctionServiceCallback.java

+1 −0

Original line number	Diff line number	Diff line
		@@ -52,6 +52,7 @@ public class RunAppFunctionServiceCallback implements RunServiceCallCallback<IAp
		@NonNull IAppFunctionService service,
		@NonNull ServiceUsageCompleteListener serviceUsageCompleteListener) {
		try {
		mSafeExecuteAppFunctionCallback.setExecutionStartTimeMillis();
		service.executeAppFunction(
		mRequestInternal.getClientRequest(),
		mRequestInternal.getCallingPackage(),