Merge "Test AppFunctions logging" into main (ff05aae2) · Commits · e / os / android_frameworks_base

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

+13 −13

Original line number	Diff line number	Diff line
		@@ -19,7 +19,6 @@ 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;
		@@ -40,8 +39,7 @@ public class SafeOneTimeExecuteAppFunctionCallback {

		@NonNull private final IExecuteAppFunctionCallback mCallback;

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

		private final AtomicLong mExecutionStartTimeAfterBindMillis = new AtomicLong();

		@@ -49,7 +47,8 @@ public class SafeOneTimeExecuteAppFunctionCallback {
		this(callback, /* completionCallback= */ null);
		}

		public SafeOneTimeExecuteAppFunctionCallback(@NonNull IExecuteAppFunctionCallback callback,
		public SafeOneTimeExecuteAppFunctionCallback(
		@NonNull IExecuteAppFunctionCallback callback,
		@Nullable CompletionCallback completionCallback) {
		mCallback = Objects.requireNonNull(callback);
		mCompletionCallback = completionCallback;
		@@ -64,8 +63,8 @@ public class SafeOneTimeExecuteAppFunctionCallback {
		try {
		mCallback.onSuccess(result);
		if (mCompletionCallback != null) {
		mCompletionCallback.finalizeOnSuccess(result,
		mExecutionStartTimeAfterBindMillis.get());
		mCompletionCallback.finalizeOnSuccess(
		result, mExecutionStartTimeAfterBindMillis.get());
		}
		} catch (RemoteException ex) {
		// Failed to notify the other end. Ignore.
		@@ -82,8 +81,8 @@ public class SafeOneTimeExecuteAppFunctionCallback {
		try {
		mCallback.onError(error);
		if (mCompletionCallback != null) {
		mCompletionCallback.finalizeOnError(error,
		mExecutionStartTimeAfterBindMillis.get());
		mCompletionCallback.finalizeOnError(
		error, mExecutionStartTimeAfterBindMillis.get());
		}
		} catch (RemoteException ex) {
		// Failed to notify the other end. Ignore.
		@@ -103,9 +102,10 @@ public class SafeOneTimeExecuteAppFunctionCallback {
		* 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()");
		public void setExecutionStartTimeAfterBindMillis(long executionStartTimeAfterBindMillis) {
		if (!mExecutionStartTimeAfterBindMillis.compareAndSet(
		0, executionStartTimeAfterBindMillis)) {
		Log.w(TAG, "Ignore subsequent calls to setExecutionStartTimeAfterBindMillis()");
		}
		}

		@@ -115,8 +115,8 @@ public class SafeOneTimeExecuteAppFunctionCallback {
		*/
		public interface CompletionCallback {
		/** Called after {@link IExecuteAppFunctionCallback#onSuccess}. */
		void finalizeOnSuccess(@NonNull ExecuteAppFunctionResponse result,
		long executionStartTimeMillis);
		void finalizeOnSuccess(
		@NonNull ExecuteAppFunctionResponse result, long executionStartTimeMillis);

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

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

+34 −17

Original line number	Diff line number	Diff line
		@@ -155,23 +155,8 @@ public class AppFunctionManagerServiceImpl extends IAppFunctionManager.Stub {
		int callingPid = Binder.getCallingPid();

		final SafeOneTimeExecuteAppFunctionCallback safeExecuteAppFunctionCallback =
		new SafeOneTimeExecuteAppFunctionCallback(executeAppFunctionCallback,
		new SafeOneTimeExecuteAppFunctionCallback.CompletionCallback() {
		@Override
		public void finalizeOnSuccess(
		@NonNull ExecuteAppFunctionResponse result,
		long executionStartTimeMillis) {
		mLoggerWrapper.logAppFunctionSuccess(requestInternal, result,
		callingUid, executionStartTimeMillis);
		}

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

		String validatedCallingPackage;
		try {
		@@ -576,6 +561,38 @@ public class AppFunctionManagerServiceImpl extends IAppFunctionManager.Stub {
		}
		}

		/**
		* Returns a new {@link SafeOneTimeExecuteAppFunctionCallback} initialized with a {@link
		* SafeOneTimeExecuteAppFunctionCallback.CompletionCallback} that logs the results.
		*/
		@VisibleForTesting
		SafeOneTimeExecuteAppFunctionCallback initializeSafeExecuteAppFunctionCallback(
		@NonNull ExecuteAppFunctionAidlRequest requestInternal,
		@NonNull IExecuteAppFunctionCallback executeAppFunctionCallback,
		int callingUid) {
		return new SafeOneTimeExecuteAppFunctionCallback(
		executeAppFunctionCallback,
		new SafeOneTimeExecuteAppFunctionCallback.CompletionCallback() {
		@Override
		public void finalizeOnSuccess(
		@NonNull ExecuteAppFunctionResponse result,
		long executionStartTimeMillis) {
		mLoggerWrapper.logAppFunctionSuccess(
		requestInternal, result, callingUid, executionStartTimeMillis);
		}

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

		private static class AppFunctionMetadataObserver implements ObserverCallback {
		@Nullable private final MetadataSyncAdapter mPerUserMetadataSyncAdapter;

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

+67 −26

Original line number	Diff line number	Diff line
		@@ -26,58 +26,99 @@ import android.content.pm.PackageManager;
		import android.os.SystemClock;
		import android.util.Slog;

		import com.android.internal.annotations.VisibleForTesting;

		import java.util.Objects;
		import java.util.concurrent.Executor;

		/** Wraps AppFunctionsStatsLog. */
		public class AppFunctionsLoggerWrapper {
		private static final String TAG = AppFunctionsLoggerWrapper.class.getSimpleName();

		private static final int SUCCESS_RESPONSE_CODE = -1;
		@VisibleForTesting static final int SUCCESS_RESPONSE_CODE = -1;

		private final PackageManager mPackageManager;
		private final Executor mLoggingExecutor;
		private final AppFunctionsLoggerClock mLoggerClock;

		private final Context mContext;
		AppFunctionsLoggerWrapper(@NonNull Context context) {
		this(context.getPackageManager(), LOGGING_THREAD_EXECUTOR, SystemClock::elapsedRealtime);
		}

		public AppFunctionsLoggerWrapper(@NonNull Context context) {
		mContext = Objects.requireNonNull(context);
		@VisibleForTesting
		AppFunctionsLoggerWrapper(
		@NonNull PackageManager packageManager,
		@NonNull Executor executor,
		AppFunctionsLoggerClock loggerClock) {
		mLoggingExecutor = Objects.requireNonNull(executor);
		mPackageManager = Objects.requireNonNull(packageManager);
		mLoggerClock = loggerClock;
		}

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

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

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

		private int getPackageUid(String packageName) {
		try {
		return mContext.getPackageManager().getPackageUid(packageName, 0);
		return mPackageManager.getPackageUid(packageName, 0);
		} catch (PackageManager.NameNotFoundException e) {
		Slog.e(TAG, "Package uid not found for " + packageName);
		}
		return 0;
		}

		/** Wraps a custom clock for easier testing. */
		interface AppFunctionsLoggerClock {
		long getCurrentTimeMillis();
		}
		}

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

+6 −4

Original line number	Diff line number	Diff line
		@@ -23,6 +23,7 @@ import android.app.appfunctions.IAppFunctionService;
		import android.app.appfunctions.ICancellationCallback;
		import android.app.appfunctions.IExecuteAppFunctionCallback;
		import android.app.appfunctions.SafeOneTimeExecuteAppFunctionCallback;
		import android.os.SystemClock;
		import android.util.Slog;

		import com.android.server.appfunctions.RemoteServiceCaller.RunServiceCallCallback;
		@@ -52,7 +53,8 @@ public class RunAppFunctionServiceCallback implements RunServiceCallCallback<IAp
		@NonNull IAppFunctionService service,
		@NonNull ServiceUsageCompleteListener serviceUsageCompleteListener) {
		try {
		mSafeExecuteAppFunctionCallback.setExecutionStartTimeMillis();
		mSafeExecuteAppFunctionCallback.setExecutionStartTimeAfterBindMillis(
		SystemClock.elapsedRealtime());
		service.executeAppFunction(
		mRequestInternal.getClientRequest(),
		mRequestInternal.getCallingPackage(),
		@@ -73,8 +75,7 @@ public class RunAppFunctionServiceCallback implements RunServiceCallCallback<IAp
		} catch (Exception e) {
		mSafeExecuteAppFunctionCallback.onError(
		new AppFunctionException(
		AppFunctionException.ERROR_APP_UNKNOWN_ERROR,
		e.getMessage()));
		AppFunctionException.ERROR_APP_UNKNOWN_ERROR, e.getMessage()));
		serviceUsageCompleteListener.onCompleted();
		}
		}
		@@ -83,7 +84,8 @@ public class RunAppFunctionServiceCallback implements RunServiceCallCallback<IAp
		public void onFailedToConnect() {
		Slog.e(TAG, "Failed to connect to service");
		mSafeExecuteAppFunctionCallback.onError(
		new AppFunctionException(AppFunctionException.ERROR_APP_UNKNOWN_ERROR,
		new AppFunctionException(
		AppFunctionException.ERROR_APP_UNKNOWN_ERROR,
		"Failed to connect to AppFunctionService"));
		}

services/tests/appfunctions/Android.bp

+6 −4

Original line number	Diff line number	Diff line
		@@ -33,18 +33,20 @@ android_test {
		],

		static_libs: [
		"androidx.core_core-ktx",
		"androidx.test.core",
		"androidx.test.runner",
		"androidx.test.ext.truth",
		"androidx.core_core-ktx",
		"androidx.test.rules",
		"androidx.test.runner",
		"frameworks-base-testutils",
		"kotlin-test",
		"kotlinx_coroutines_test",
		"mockito-kotlin2",
		"mockito-target-extended-minus-junit4",
		"platform-test-annotations",
		"services.appfunctions",
		"servicestests-core-utils",
		"truth",
		"frameworks-base-testutils",
		"androidx.test.rules",
		],

		libs: [