diff options
7 files changed, 162 insertions, 32 deletions
diff --git a/core/java/android/service/autofill/augmented/AugmentedAutofillService.java b/core/java/android/service/autofill/augmented/AugmentedAutofillService.java index 656127ad77a9..87e369f20d58 100644 --- a/core/java/android/service/autofill/augmented/AugmentedAutofillService.java +++ b/core/java/android/service/autofill/augmented/AugmentedAutofillService.java @@ -15,6 +15,9 @@ */ package android.service.autofill.augmented; +import static android.service.autofill.augmented.Helper.logResponse; +import static android.util.TimeUtils.formatDuration; + import static com.android.internal.util.function.pooled.PooledLambda.obtainMessage; import android.annotation.CallSuper; @@ -38,9 +41,7 @@ import android.os.SystemClock; import android.service.autofill.augmented.PresentationParams.SystemPopupPresentationParams; import android.util.Log; import android.util.Pair; -import android.util.Slog; import android.util.SparseArray; -import android.util.TimeUtils; import android.view.autofill.AutofillId; import android.view.autofill.AutofillManager; import android.view.autofill.AutofillValue; @@ -48,6 +49,7 @@ import android.view.autofill.IAugmentedAutofillManagerClient; import android.view.autofill.IAutofillWindowPresenter; import com.android.internal.annotations.GuardedBy; +import com.android.internal.logging.nano.MetricsProto.MetricsEvent; import java.io.FileDescriptor; import java.io.PrintWriter; @@ -84,6 +86,9 @@ public abstract class AugmentedAutofillService extends Service { private SparseArray<AutofillProxy> mAutofillProxies; + // Used for metrics / debug only + private ComponentName mServiceComponentName; + private final IAugmentedAutofillService mInterface = new IAugmentedAutofillService.Stub() { @Override @@ -125,6 +130,7 @@ public abstract class AugmentedAutofillService extends Service { /** @hide */ @Override public final IBinder onBind(Intent intent) { + mServiceComponentName = intent.getComponent(); if (SERVICE_INTERFACE.equals(intent.getAction())) { return mInterface.asBinder(); } @@ -215,8 +221,9 @@ public abstract class AugmentedAutofillService extends Service { final CancellationSignal cancellationSignal = CancellationSignal.fromTransport(transport); AutofillProxy proxy = mAutofillProxies.get(sessionId); if (proxy == null) { - proxy = new AutofillProxy(sessionId, client, taskId, componentName, focusedId, - focusedValue, requestTime, callback, cancellationSignal); + proxy = new AutofillProxy(sessionId, client, taskId, mServiceComponentName, + componentName, focusedId, focusedValue, requestTime, callback, + cancellationSignal); mAutofillProxies.put(sessionId, proxy); } else { // TODO(b/123099468): figure out if it's ok to reuse the proxy; add logging @@ -272,6 +279,8 @@ public abstract class AugmentedAutofillService extends Service { @Override /** @hide */ protected final void dump(FileDescriptor fd, PrintWriter pw, String[] args) { + pw.print("Service component: "); pw.println( + ComponentName.flattenToShortString(mServiceComponentName)); if (mAutofillProxies != null) { final int size = mAutofillProxies.size(); pw.print("Number proxies: "); pw.println(size); @@ -301,12 +310,12 @@ public abstract class AugmentedAutofillService extends Service { /** @hide */ static final class AutofillProxy { - static final int REPORT_EVENT_ON_SUCCESS = 1; + static final int REPORT_EVENT_NO_RESPONSE = 1; static final int REPORT_EVENT_UI_SHOWN = 2; static final int REPORT_EVENT_UI_DESTROYED = 3; @IntDef(prefix = { "REPORT_EVENT_" }, value = { - REPORT_EVENT_ON_SUCCESS, + REPORT_EVENT_NO_RESPONSE, REPORT_EVENT_UI_SHOWN, REPORT_EVENT_UI_DESTROYED }) @@ -319,6 +328,8 @@ public abstract class AugmentedAutofillService extends Service { private final int mSessionId; public final int taskId; public final ComponentName componentName; + // Used for metrics / debug only + private String mServicePackageName; @GuardedBy("mLock") private AutofillId mFocusedId; @GuardedBy("mLock") @@ -349,6 +360,7 @@ public abstract class AugmentedAutofillService extends Service { private CancellationSignal mCancellationSignal; private AutofillProxy(int sessionId, @NonNull IBinder client, int taskId, + @NonNull ComponentName serviceComponentName, @NonNull ComponentName componentName, @NonNull AutofillId focusedId, @Nullable AutofillValue focusedValue, long requestTime, @NonNull IFillCallback callback, @NonNull CancellationSignal cancellationSignal) { @@ -357,6 +369,7 @@ public abstract class AugmentedAutofillService extends Service { mCallback = callback; this.taskId = taskId; this.componentName = componentName; + mServicePackageName = serviceComponentName.getPackageName(); mFocusedId = focusedId; mFocusedValue = focusedValue; mFirstRequestTime = requestTime; @@ -439,9 +452,9 @@ public abstract class AugmentedAutofillService extends Service { mCallback.cancel(); } } catch (RemoteException e) { - Slog.e(TAG, "failed to check current pending request status", e); + Log.e(TAG, "failed to check current pending request status", e); } - Slog.d(TAG, "mCallback is updated."); + Log.d(TAG, "mCallback is updated."); } mCallback = callback; } @@ -463,13 +476,17 @@ public abstract class AugmentedAutofillService extends Service { // Used (mostly) for metrics. public void report(@ReportEvent int event) { + if (sVerbose) Log.v(TAG, "report(): " + event); + long duration = -1; + int type = MetricsEvent.TYPE_UNKNOWN; switch (event) { - case REPORT_EVENT_ON_SUCCESS: + case REPORT_EVENT_NO_RESPONSE: + type = MetricsEvent.TYPE_SUCCESS; if (mFirstOnSuccessTime == 0) { mFirstOnSuccessTime = SystemClock.elapsedRealtime(); + duration = mFirstOnSuccessTime - mFirstRequestTime; if (sDebug) { - Slog.d(TAG, "Service responded in " + TimeUtils.formatDuration( - mFirstOnSuccessTime - mFirstRequestTime)); + Log.d(TAG, "Service responded nothing in " + formatDuration(duration)); } } try { @@ -479,27 +496,25 @@ public abstract class AugmentedAutofillService extends Service { } break; case REPORT_EVENT_UI_SHOWN: + type = MetricsEvent.TYPE_OPEN; if (mUiFirstShownTime == 0) { mUiFirstShownTime = SystemClock.elapsedRealtime(); - if (sDebug) { - Slog.d(TAG, "UI shown in " + TimeUtils.formatDuration( - mUiFirstShownTime - mFirstRequestTime)); - } + duration = mUiFirstShownTime - mFirstRequestTime; + if (sDebug) Log.d(TAG, "UI shown in " + formatDuration(duration)); } break; case REPORT_EVENT_UI_DESTROYED: + type = MetricsEvent.TYPE_CLOSE; if (mUiFirstDestroyedTime == 0) { mUiFirstDestroyedTime = SystemClock.elapsedRealtime(); - if (sDebug) { - Slog.d(TAG, "UI destroyed in " + TimeUtils.formatDuration( - mUiFirstDestroyedTime - mFirstRequestTime)); - } + duration = mUiFirstDestroyedTime - mFirstRequestTime; + if (sDebug) Log.d(TAG, "UI destroyed in " + formatDuration(duration)); } break; default: - Slog.w(TAG, "invalid event reported: " + event); + Log.w(TAG, "invalid event reported: " + event); } - // TODO(b/122858578): log metrics as well + logResponse(type, mServicePackageName, componentName, mSessionId, duration); } public void dump(@NonNull String prefix, @NonNull PrintWriter pw) { @@ -527,19 +542,19 @@ public abstract class AugmentedAutofillService extends Service { if (mFirstOnSuccessTime > 0) { final long responseTime = mFirstOnSuccessTime - mFirstRequestTime; pw.print(prefix); pw.print("response time: "); - TimeUtils.formatDuration(responseTime, pw); pw.println(); + formatDuration(responseTime, pw); pw.println(); } if (mUiFirstShownTime > 0) { final long uiRenderingTime = mUiFirstShownTime - mFirstRequestTime; pw.print(prefix); pw.print("UI rendering time: "); - TimeUtils.formatDuration(uiRenderingTime, pw); pw.println(); + formatDuration(uiRenderingTime, pw); pw.println(); } if (mUiFirstDestroyedTime > 0) { final long uiTotalTime = mUiFirstDestroyedTime - mFirstRequestTime; pw.print(prefix); pw.print("UI life time: "); - TimeUtils.formatDuration(uiTotalTime, pw); pw.println(); + formatDuration(uiTotalTime, pw); pw.println(); } } diff --git a/core/java/android/service/autofill/augmented/FillCallback.java b/core/java/android/service/autofill/augmented/FillCallback.java index 33e6a8c25ba4..0251386bd7ce 100644 --- a/core/java/android/service/autofill/augmented/FillCallback.java +++ b/core/java/android/service/autofill/augmented/FillCallback.java @@ -50,8 +50,10 @@ public final class FillCallback { public void onSuccess(@Nullable FillResponse response) { if (sDebug) Log.d(TAG, "onSuccess(): " + response); - mProxy.report(AutofillProxy.REPORT_EVENT_ON_SUCCESS); - if (response == null) return; + if (response == null) { + mProxy.report(AutofillProxy.REPORT_EVENT_NO_RESPONSE); + return; + } final FillWindow fillWindow = response.getFillWindow(); if (fillWindow != null) { diff --git a/core/java/android/service/autofill/augmented/Helper.java b/core/java/android/service/autofill/augmented/Helper.java new file mode 100644 index 000000000000..501696f99c66 --- /dev/null +++ b/core/java/android/service/autofill/augmented/Helper.java @@ -0,0 +1,48 @@ +/* + * Copyright (C) 2019 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package android.service.autofill.augmented; + +import android.annotation.NonNull; +import android.content.ComponentName; +import android.metrics.LogMaker; + +import com.android.internal.logging.MetricsLogger; +import com.android.internal.logging.nano.MetricsProto.MetricsEvent; + +/** @hide */ +public final class Helper { + + private static final MetricsLogger sMetricsLogger = new MetricsLogger(); + + /** + * Logs a {@code MetricsEvent.AUTOFILL_AUGMENTED_RESPONSE} event. + */ + public static void logResponse(int type, @NonNull String servicePackageName, + @NonNull ComponentName componentName, int mSessionId, long durationMs) { + final LogMaker log = new LogMaker(MetricsEvent.AUTOFILL_AUGMENTED_RESPONSE) + .setType(type) + .setComponentName(componentName) + .addTaggedData(MetricsEvent.FIELD_AUTOFILL_SESSION_ID, mSessionId) + .addTaggedData(MetricsEvent.FIELD_AUTOFILL_SERVICE, servicePackageName) + .addTaggedData(MetricsEvent.FIELD_AUTOFILL_DURATION, durationMs); + System.out.println("LOGGGO: " + log.getEntries()); // felipeal: tmp + sMetricsLogger.write(log); + } + + private Helper() { + throw new UnsupportedOperationException("contains only static methods"); + } +} diff --git a/proto/src/metrics_constants/metrics_constants.proto b/proto/src/metrics_constants/metrics_constants.proto index fa62f64d59ca..e30e166a46b5 100644 --- a/proto/src/metrics_constants/metrics_constants.proto +++ b/proto/src/metrics_constants/metrics_constants.proto @@ -4191,6 +4191,8 @@ message MetricsEvent { // Tag FIELD_AUTOFILL_COMPAT_MODE: package is being autofilled on compatibility mode. // Tag FIELD_AUTOFILL_NUMBER_REQUESTS: number of requests made to the service (each request // is logged by a separate AUTOFILL_REQUEST metric) + // NOTE: starting on OS Q, it also added the following fields: + // TAg FIELD_AUTOFILL_AUGMENTED_ONLY: if the session was used just for augmented autofill AUTOFILL_SESSION_FINISHED = 919; // meta-event: a reader has checkpointed the log here. @@ -7243,8 +7245,46 @@ message MetricsEvent { // OS: Q ACTION_DIRECT_SHARE_TARGETS_LOADED_CHOOSER_SERVICE = 1719; - // ---- Skipping ahead to avoid conflicts between master and release branches. + // Field indicating that an autofill session was created just for augmented autofill purposes. + // OS: Q + // Value: 1 for true, absent when false + FIELD_AUTOFILL_AUGMENTED_ONLY = 1720; + + // The augmented autofill service set its whitelisted packages and activities. + // OS: Q + // Tag FIELD_AUTOFILL_SERVICE: Package of the augmented autofill service that processed the + // request + // Tag FIELD_AUTOFILL_NUMBER_PACKAGES: Number of whitelisted packages. + // Tag FIELD_AUTOFILL_NUMBER_ACTIVITIES: Number of whitelisted activities. + AUTOFILL_AUGMENTED_WHITELIST_REQUEST = 1721; + + // Generic field used to indicate the number of packages in an Autofill metric (typically a + // whitelist request). + // OS: Q + FIELD_AUTOFILL_NUMBER_PACKAGES = 1722; + // Generic field used to indicate the number of activities in an Autofill metric (typically a + // whitelist request). + // OS: Q + FIELD_AUTOFILL_NUMBER_ACTIVITIES = 1723; + + // Reports the result of a request made to the augmented autofill service + // OS: Q + // Type TYPE_UNKNOWN: if the type of response could not be determined + // Type TYPE_SUCCESS: service called onSucess() passing null + // Type TYPE_OPEN: service shown the UI + // Type TYPE_CLOSE: service hid the UI + // Type TYPE_ERROR: service timed out responding + + // Tag FIELD_CLASS_NAME: Class name of the activity that is autofilled. + // Tag FIELD_AUTOFILL_SERVICE: Package of the augmented autofill service that processed the + // request + // Tag FIELD_AUTOFILL_SESSION_ID: id of the autofill session associated with this metric + // Tag FIELD_AUTOFILL_DURATION: how long it took (in ms) to the service to respond, or -1 if the + // type of response could not be determined + AUTOFILL_AUGMENTED_RESPONSE = 1724; + + // ---- Skipping ahead to avoid conflicts between master and release branches. // OPEN: Settings > System > Gestures > Global Actions Panel // CATEGORY: SETTINGS // OS: Q diff --git a/services/autofill/java/com/android/server/autofill/AutofillManagerServiceImpl.java b/services/autofill/java/com/android/server/autofill/AutofillManagerServiceImpl.java index 386dec472019..6bb1cfaf11c2 100644 --- a/services/autofill/java/com/android/server/autofill/AutofillManagerServiceImpl.java +++ b/services/autofill/java/com/android/server/autofill/AutofillManagerServiceImpl.java @@ -1177,8 +1177,8 @@ final class AutofillManagerServiceImpl * @return whether caller UID is the augmented autofill service for the user */ @GuardedBy("mLock") - boolean setAugmentedAutofillWhitelistLocked(List<String> packages, - List<ComponentName> activities, int callingUid) { + boolean setAugmentedAutofillWhitelistLocked(@Nullable List<String> packages, + @Nullable List<ComponentName> activities, int callingUid) { if (!isCalledByAugmentedAutofillServiceLocked("setAugmentedAutofillWhitelistLocked", callingUid)) { @@ -1189,8 +1189,25 @@ final class AutofillManagerServiceImpl + activities + ")"); } whitelistForAugmentedAutofillPackages(packages, activities); + final String serviceName; + if (mRemoteAugmentedAutofillServiceInfo != null) { + serviceName = mRemoteAugmentedAutofillServiceInfo.getComponentName() + .flattenToShortString(); + } else { + Slog.e(TAG, "setAugmentedAutofillWhitelistLocked(): no service"); + serviceName = "N/A"; + } + + final LogMaker log = new LogMaker(MetricsEvent.AUTOFILL_AUGMENTED_WHITELIST_REQUEST) + .addTaggedData(MetricsEvent.FIELD_AUTOFILL_SERVICE, serviceName); + if (packages != null) { + log.addTaggedData(MetricsEvent.FIELD_AUTOFILL_NUMBER_PACKAGES, packages.size()); + } + if (activities != null) { + log.addTaggedData(MetricsEvent.FIELD_AUTOFILL_NUMBER_ACTIVITIES, activities.size()); + } + mMetricsLogger.write(log); - // TODO(b/122858578): log metrics return true; } @@ -1233,7 +1250,6 @@ final class AutofillManagerServiceImpl } /** - * * @throws IllegalArgumentException if packages or components are empty. */ private void whitelistForAugmentedAutofillPackages(@Nullable List<String> packages, diff --git a/services/autofill/java/com/android/server/autofill/RemoteAugmentedAutofillService.java b/services/autofill/java/com/android/server/autofill/RemoteAugmentedAutofillService.java index 609904b32230..d2b71e591b22 100644 --- a/services/autofill/java/com/android/server/autofill/RemoteAugmentedAutofillService.java +++ b/services/autofill/java/com/android/server/autofill/RemoteAugmentedAutofillService.java @@ -16,6 +16,8 @@ package com.android.server.autofill; +import static android.service.autofill.augmented.Helper.logResponse; + import static com.android.server.autofill.Helper.sDebug; import static com.android.server.autofill.Helper.sVerbose; @@ -43,6 +45,7 @@ import android.view.autofill.AutofillValue; import android.view.autofill.IAutoFillManagerClient; import com.android.internal.infra.AbstractSinglePendingRequestRemoteService; +import com.android.internal.logging.nano.MetricsProto.MetricsEvent; import com.android.internal.os.IResultReceiver; final class RemoteAugmentedAutofillService @@ -173,6 +176,7 @@ final class RemoteAugmentedAutofillService private final @Nullable AutofillValue mFocusedValue; private final @NonNull IAutoFillManagerClient mClient; private final @NonNull ComponentName mActivityComponent; + private final int mSessionId; private final int mTaskId; private final long mRequestTime = SystemClock.elapsedRealtime(); private final @NonNull IFillCallback mCallback; @@ -184,6 +188,7 @@ final class RemoteAugmentedAutofillService @Nullable AutofillValue focusedValue) { super(service, sessionId); mClient = client; + mSessionId = sessionId; mTaskId = taskId; mActivityComponent = activityComponent; mFocusedId = focusedId; @@ -283,6 +288,8 @@ final class RemoteAugmentedAutofillService remoteService.dispatchOnFillTimeout(cancellation); } finish(); + logResponse(MetricsEvent.TYPE_ERROR, remoteService.getComponentName().getPackageName(), + mActivityComponent, mSessionId, remoteService.mRequestTimeoutMs); } @Override diff --git a/services/autofill/java/com/android/server/autofill/Session.java b/services/autofill/java/com/android/server/autofill/Session.java index 1a0353cde8ce..e61fa326215f 100644 --- a/services/autofill/java/com/android/server/autofill/Session.java +++ b/services/autofill/java/com/android/server/autofill/Session.java @@ -570,7 +570,6 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState private void requestNewFillResponseLocked(@NonNull ViewState viewState, int newState, int flags) { if (mForAugmentedAutofillOnly) { - // TODO(b/122858578): log metrics if (sVerbose) { Slog.v(TAG, "requestNewFillResponse(): triggering augmented autofill instead " + "(mForAugmentedAutofillOnly=" + mForAugmentedAutofillOnly @@ -3253,6 +3252,9 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState log.addTaggedData(MetricsEvent.FIELD_AUTOFILL_NUMBER_AUGMENTED_REQUESTS, totalAugmentedRequests); } + if (mForAugmentedAutofillOnly) { + log.addTaggedData(MetricsEvent.FIELD_AUTOFILL_AUGMENTED_ONLY, 1); + } mMetricsLogger.write(log); return mRemoteFillService; |