Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Added moar augmented-autofill metrics:

Browse Source 
- AUTOFILL_AUGMENTED_WHITELIST_REQUEST
- AUTOFILL_AUGMENTED_RESPONSE
- FIELD_AUTOFILL_AUGMENTED_ONLY on AUTOFILL_SESSION_FINISHED

Test: adb shell logcat -b events | grep sysui
Test: atest CtsContentCaptureServiceTestCases # sanity check

Bug: 112192360
Fixes: 122858578

Change-Id: Ia6bfced9396dd9e3f8ef2a6c45415dc22f4327c9
This commit is contained in:
Felipe Leme
2019-05-02 14:09:04 -07:00
parent cf644aa292
commit b8662f1201
7 changed files with 161 additions and 33 deletions
Download Patch File Download Diff File Expand all files Collapse all files

63
core/java/android/service/autofill/augmented/AugmentedAutofillService.java
View File

@@ -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();
}
}

6
core/java/android/service/autofill/augmented/FillCallback.java
View File

@@ -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) {

47
core/java/android/service/autofill/augmented/Helper.java Normal file
View File

@@ -0,0 +1,47 @@
/*
* 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);
sMetricsLogger.write(log);
}
private Helper() {
throw new UnsupportedOperationException("contains only static methods");
}
}

41
proto/src/metrics_constants/metrics_constants.proto
View File

@@ -4183,6 +4183,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.
@@ -7222,6 +7224,45 @@ message MetricsEvent {
// OS: Q
ASSISTANT = 1716;
// 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 = 1717;
// 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 = 1718;
// Generic field used to indicate the number of packages in an Autofill metric (typically a
// whitelist request).
// OS: Q
FIELD_AUTOFILL_NUMBER_PACKAGES = 1719;
// Generic field used to indicate the number of activities in an Autofill metric (typically a
// whitelist request).
// OS: Q
FIELD_AUTOFILL_NUMBER_ACTIVITIES = 1720;
// 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 = 1721;
// ---- End Q Constants, all Q constants go above this line ----
// Add new aosp constants above this line.
// END OF AOSP CONSTANTS

24
services/autofill/java/com/android/server/autofill/AutofillManagerServiceImpl.java
View File

@@ -1195,8 +1195,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)) {
@@ -1207,8 +1207,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;
}
@@ -1251,7 +1268,6 @@ final class AutofillManagerServiceImpl
}
/**
*
* @throws IllegalArgumentException if packages or components are empty.
*/
private void whitelistForAugmentedAutofillPackages(@Nullable List<String> packages,

9
services/autofill/java/com/android/server/autofill/RemoteAugmentedAutofillService.java
View File

@@ -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;
@@ -47,6 +49,7 @@ import android.view.autofill.IAutoFillManagerClient;
import com.android.internal.infra.AbstractRemoteService;
import com.android.internal.infra.AndroidFuture;
import com.android.internal.infra.ServiceConnector;
import com.android.internal.logging.nano.MetricsProto.MetricsEvent;
import com.android.internal.os.IResultReceiver;
import java.util.concurrent.CancellationException;
@@ -181,12 +184,14 @@ final class RemoteAugmentedAutofillService
if (err instanceof CancellationException) {
dispatchCancellation(cancellationRef.get());
} else if (err instanceof TimeoutException) {
// TODO(b/122858578): must update the logged AUTOFILL_AUGMENTED_REQUEST with
// the timeout
Slog.w(TAG, "PendingAutofillRequest timed out (" + mRequestTimeoutMs
+ "ms) for " + RemoteAugmentedAutofillService.this);
// NOTE: so far we don't need notify RemoteAugmentedAutofillServiceCallbacks
dispatchCancellation(cancellationRef.get());
if (mComponentName != null) {
logResponse(MetricsEvent.TYPE_ERROR, mComponentName.getPackageName(),
activityComponent, sessionId, mRequestTimeoutMs);
}
} else if (err != null) {
Slog.e(TAG, "exception handling getAugmentedAutofillClient() for "
+ sessionId + ": ", err);

4
services/autofill/java/com/android/server/autofill/Session.java
View File

@@ -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;