Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit f54823d1 authored by Yara Hassan's avatar Yara Hassan
Browse files

Test AppFunctions logging 

Add tests that verify AppFunctionsStatsLog is called with the expected values when the appfunction service reports a result or error.

Flag: android.app.appfunctions.flags.enable_app_function_manager
Bug: 376688078
Test: unit tests
Change-Id: Ia1b23644726e2d497af39c02be5d97f77786b388
parent 9f05161c

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: [