[Autofill PCC Metrics]:Follow-up: Populate PCC relevant metrics

Populate additional PCC related metrics, providing the full picture.
Test: m
Bug: 265037574

Change-Id: If2a05d4a1693d0217b7fb5062e308dddc68d341c
This commit is contained in:
Simranjit Kohli
2023-05-16 02:35:43 -07:00
parent 34007030cf
commit b0814675e5
3 changed files with 154 additions and 31 deletions

View File

@@ -26,6 +26,9 @@ import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__AUTHENTICATION_TYPE__AUTHENTICATION_TYPE_UNKNOWN;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__AUTHENTICATION_TYPE__DATASET_AUTHENTICATION;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__AUTHENTICATION_TYPE__FULL_AUTHENTICATION;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_AUTOFILL_PROVIDER;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_PCC;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_UNKONWN;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DISPLAY_PRESENTATION_TYPE__DIALOG;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DISPLAY_PRESENTATION_TYPE__INLINE;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DISPLAY_PRESENTATION_TYPE__MENU;
@@ -40,6 +43,7 @@ import static com.android.server.autofill.Helper.sVerbose;
import android.annotation.IntDef;
import android.annotation.Nullable;
import android.os.SystemClock;
import android.service.autofill.Dataset;
import android.util.Slog;
import android.view.autofill.AutofillId;
@@ -57,6 +61,9 @@ import java.util.Optional;
public final class FillResponseEventLogger {
private static final String TAG = "FillResponseEventLogger";
private static final long UNINITIALIZED_TIMESTAMP = -1;
private long startResponseProcessingTimestamp = UNINITIALIZED_TIMESTAMP;
/**
* Reasons why presentation was not shown. These are wrappers around
* {@link com.android.os.AtomsProto.AutofillFillRequestReported.RequestTriggerReason}.
@@ -114,6 +121,20 @@ public final class FillResponseEventLogger {
public @interface AuthenticationResult {
}
/**
* Reasons why presentation was not shown. These are wrappers around
* {@link com.android.os.AtomsProto.AutofillFillResponseReported.DetectionPreference}.
*/
@IntDef(prefix = {"DETECTION_PREFER"}, value = {
DETECTION_PREFER_UNKNOWN,
DETECTION_PREFER_AUTOFILL_PROVIDER,
DETECTION_PREFER_PCC
})
@Retention(RetentionPolicy.SOURCE)
public @interface DetectionPreference {
}
public static final int DISPLAY_PRESENTATION_TYPE_UNKNOWN =
AUTOFILL_FILL_RESPONSE_REPORTED__DISPLAY_PRESENTATION_TYPE__UNKNOWN_AUTOFILL_DISPLAY_PRESENTATION_TYPE;
public static final int DISPLAY_PRESENTATION_TYPE_MENU =
@@ -148,6 +169,15 @@ public final class FillResponseEventLogger {
public static final int RESPONSE_STATUS_UNKNOWN =
AUTOFILL_FILL_RESPONSE_REPORTED__RESPONSE_STATUS__RESPONSE_STATUS_UNKNOWN;
// Values for AutofillFillResponseReported.detection_preference
public static final int DETECTION_PREFER_UNKNOWN =
AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_UNKONWN;
public static final int DETECTION_PREFER_AUTOFILL_PROVIDER =
AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_AUTOFILL_PROVIDER;
public static final int DETECTION_PREFER_PCC =
AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_PCC;
// Log a magic number when FillRequest failed or timeout to differentiate with FillRequest
// succeeded.
public static final int AVAILABLE_COUNT_WHEN_FILL_REQUEST_FAILED_OR_TIMEOUT = -1;
@@ -220,6 +250,12 @@ public final class FillResponseEventLogger {
}
public void maybeSetAvailableCount(int val) {
mEventInternal.ifPresent(event -> {
event.mAvailableCount = val;
});
}
public void maybeSetTotalDatasetsProvided(int val) {
mEventInternal.ifPresent(event -> {
// Don't reset if it's already populated.
// This is just a technical limitation of not having complicated logic.
@@ -227,9 +263,9 @@ public final class FillResponseEventLogger {
// In such a case, we set available count to the number of datasets provided.
// However, it's possible that those data types aren't detected by PCC, so in effect, there
// are 0 datasets. In the codebase, we treat it as null response, which may call this again
// to set 0. But we don't want to overwrite this value.
if (event.mAvailableCount == 0) {
event.mAvailableCount = val;
// to set 0. But we don't want to overwrite already set value.
if (event.mTotalDatasetsProvided == -1) {
event.mTotalDatasetsProvided = val;
}
});
}
@@ -321,12 +357,20 @@ public final class FillResponseEventLogger {
});
}
public void startResponseProcessingTime() {
startResponseProcessingTimestamp = SystemClock.elapsedRealtime();
}
/**
* Set latency_response_processing_millis as long as mEventInternal presents.
*/
public void maybeSetLatencyResponseProcessingMillis(int val) {
public void maybeSetLatencyResponseProcessingMillis() {
mEventInternal.ifPresent(event -> {
event.mLatencyResponseProcessingMillis = val;
if (startResponseProcessingTimestamp == UNINITIALIZED_TIMESTAMP && sVerbose) {
Slog.v(TAG, "uninitialized startResponseProcessingTimestamp");
}
event.mLatencyResponseProcessingMillis
= SystemClock.elapsedRealtime() - startResponseProcessingTimestamp;
});
}
@@ -351,11 +395,13 @@ public final class FillResponseEventLogger {
/**
* Set available_pcc_count.
*/
public void maybeSetAvailableDatasetsPccCount(@Nullable List<Dataset> datasetList) {
public void maybeSetDatasetsCountAfterPotentialPccFiltering(@Nullable List<Dataset> datasetList) {
mEventInternal.ifPresent(event -> {
int pccOnlyCount = 0;
int pccCount = 0;
int totalCount = 0;
if (datasetList != null) {
totalCount = datasetList.size();
for (int i = 0; i < datasetList.size(); i++) {
Dataset dataset = datasetList.get(i);
if (dataset != null) {
@@ -371,9 +417,18 @@ public final class FillResponseEventLogger {
}
event.mAvailablePccOnlyCount = pccOnlyCount;
event.mAvailablePccCount = pccCount;
event.mAvailableCount = totalCount;
});
}
/**
* Set detection_pref
*/
public void maybeSetDetectionPreference(@DetectionPreference int detectionPreference) {
mEventInternal.ifPresent(event -> {
event.mDetectionPref = detectionPreference;
});
}
/**
* Log an AUTOFILL_FILL_RESPONSE_REPORTED event.
@@ -402,7 +457,9 @@ public final class FillResponseEventLogger {
+ " mResponseStatus=" + event.mResponseStatus
+ " mLatencyResponseProcessingMillis=" + event.mLatencyResponseProcessingMillis
+ " mAvailablePccCount=" + event.mAvailablePccCount
+ " mAvailablePccOnlyCount=" + event.mAvailablePccOnlyCount);
+ " mAvailablePccOnlyCount=" + event.mAvailablePccOnlyCount
+ " mTotalDatasetsProvided=" + event.mTotalDatasetsProvided
+ " mDetectionPref=" + event.mDetectionPref);
}
FrameworkStatsLog.write(
AUTOFILL_FILL_RESPONSE_REPORTED,
@@ -421,7 +478,9 @@ public final class FillResponseEventLogger {
event.mResponseStatus,
event.mLatencyResponseProcessingMillis,
event.mAvailablePccCount,
event.mAvailablePccOnlyCount);
event.mAvailablePccOnlyCount,
event.mTotalDatasetsProvided,
event.mDetectionPref);
mEventInternal = Optional.empty();
}
@@ -431,16 +490,19 @@ public final class FillResponseEventLogger {
int mDisplayPresentationType = DISPLAY_PRESENTATION_TYPE_UNKNOWN;
int mAvailableCount = 0;
int mSaveUiTriggerIds = -1;
int mLatencyFillResponseReceivedMillis = 0;
int mLatencyFillResponseReceivedMillis = (int) UNINITIALIZED_TIMESTAMP;
int mAuthenticationType = AUTHENTICATION_TYPE_UNKNOWN;
int mAuthenticationResult = AUTHENTICATION_RESULT_UNKNOWN;
int mAuthenticationFailureReason = -1;
int mLatencyAuthenticationUiDisplayMillis = 0;
int mLatencyDatasetDisplayMillis = 0;
int mLatencyAuthenticationUiDisplayMillis = (int) UNINITIALIZED_TIMESTAMP;
int mLatencyDatasetDisplayMillis = (int) UNINITIALIZED_TIMESTAMP;
int mResponseStatus = RESPONSE_STATUS_UNKNOWN;
int mLatencyResponseProcessingMillis = 0;
int mAvailablePccCount;
int mAvailablePccOnlyCount;
long mLatencyResponseProcessingMillis = UNINITIALIZED_TIMESTAMP;
int mAvailablePccCount = -1;
int mAvailablePccOnlyCount = -1;
int mTotalDatasetsProvided = -1;
@DetectionPreference
int mDetectionPref = DETECTION_PREFER_UNKNOWN;
FillResponseEventInternal() {
}

View File

@@ -16,8 +16,6 @@
package com.android.server.autofill;
import static android.service.autofill.Dataset.PICK_REASON_PCC_DETECTION_ONLY;
import static android.service.autofill.Dataset.PICK_REASON_PCC_DETECTION_PREFERRED_WITH_PROVIDER;
import static android.service.autofill.FillEventHistory.Event.UI_TYPE_DIALOG;
import static android.service.autofill.FillEventHistory.Event.UI_TYPE_INLINE;
import static android.service.autofill.FillEventHistory.Event.UI_TYPE_MENU;
@@ -27,6 +25,9 @@ import static android.view.autofill.AutofillManager.COMMIT_REASON_VIEW_CHANGED;
import static android.view.autofill.AutofillManager.COMMIT_REASON_VIEW_CLICKED;
import static android.view.autofill.AutofillManager.COMMIT_REASON_VIEW_COMMITTED;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_AUTOFILL_PROVIDER;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_PCC;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_UNKONWN;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__AUTHENTICATION_RESULT__AUTHENTICATION_FAILURE;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__AUTHENTICATION_RESULT__AUTHENTICATION_RESULT_UNKNOWN;
@@ -140,6 +141,19 @@ public final class PresentationStatsEventLogger {
@Retention(RetentionPolicy.SOURCE)
public @interface DatasetPickedReason {}
/**
* The type of detection that was preferred. These are wrappers around
* {@link com.android.os.AtomsProto.AutofillPresentationEventReported.DetectionPreference}.
*/
@IntDef(prefix = {"DETECTION_PREFER"}, value = {
DETECTION_PREFER_UNKNOWN,
DETECTION_PREFER_AUTOFILL_PROVIDER,
DETECTION_PREFER_PCC
})
@Retention(RetentionPolicy.SOURCE)
public @interface DetectionPreference {
}
public static final int NOT_SHOWN_REASON_ANY_SHOWN =
AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__ANY_SHOWN;
public static final int NOT_SHOWN_REASON_VIEW_FOCUS_CHANGED =
@@ -187,6 +201,15 @@ public final class PresentationStatsEventLogger {
AUTOFILL_PRESENTATION_EVENT_REPORTED__SELECTED_DATASET_PICKED_REASON__PICK_REASON_PCC_DETECTION_ONLY;
public static final int PICK_REASON_PCC_DETECTION_PREFERRED_WITH_PROVIDER =
AUTOFILL_PRESENTATION_EVENT_REPORTED__SELECTED_DATASET_PICKED_REASON__PICK_REASON_PCC_DETECTION_PREFERRED_WITH_PROVIDER;
// Values for AutofillFillResponseReported.detection_preference
public static final int DETECTION_PREFER_UNKNOWN =
AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_UNKONWN;
public static final int DETECTION_PREFER_AUTOFILL_PROVIDER =
AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_AUTOFILL_PROVIDER;
public static final int DETECTION_PREFER_PCC =
AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_PCC;
private final int mSessionId;
private Optional<PresentationStatsEventInternal> mEventInternal;
@@ -463,6 +486,15 @@ public final class PresentationStatsEventLogger {
});
}
/**
* Set detection_pref
*/
public void maybeSetDetectionPreference(@DetectionPreference int detectionPreference) {
mEventInternal.ifPresent(event -> {
event.mDetectionPreference = detectionPreference;
});
}
private int convertDatasetPickReason(@Dataset.DatasetEligibleReason int val) {
switch (val) {
case 0:
@@ -514,7 +546,8 @@ public final class PresentationStatsEventLogger {
+ " mLatencyDatasetDisplayMillis=" + event.mLatencyDatasetDisplayMillis
+ " mAvailablePccCount=" + event.mAvailablePccCount
+ " mAvailablePccOnlyCount=" + event.mAvailablePccOnlyCount
+ " mSelectedDatasetPickedReason=" + event.mSelectedDatasetPickedReason);
+ " mSelectedDatasetPickedReason=" + event.mSelectedDatasetPickedReason
+ " mDetectionPreference=" + event.mDetectionPreference);
}
// TODO(b/234185326): Distinguish empty responses from other no presentation reasons.
@@ -550,7 +583,8 @@ public final class PresentationStatsEventLogger {
event.mLatencyDatasetDisplayMillis,
event.mAvailablePccCount,
event.mAvailablePccOnlyCount,
event.mSelectedDatasetPickedReason);
event.mSelectedDatasetPickedReason,
event.mDetectionPreference);
mEventInternal = Optional.empty();
}
@@ -582,6 +616,7 @@ public final class PresentationStatsEventLogger {
int mAvailablePccCount = -1;
int mAvailablePccOnlyCount = -1;
@DatasetPickedReason int mSelectedDatasetPickedReason = PICK_REASON_UNKNOWN;
@DetectionPreference int mDetectionPreference = DETECTION_PREFER_UNKNOWN;
PresentationStatsEventInternal() {}
}

View File

@@ -52,6 +52,9 @@ import static com.android.server.autofill.FillRequestEventLogger.TRIGGER_REASON_
import static com.android.server.autofill.FillRequestEventLogger.TRIGGER_REASON_PRE_TRIGGER;
import static com.android.server.autofill.FillRequestEventLogger.TRIGGER_REASON_SERVED_FROM_CACHED_RESPONSE;
import static com.android.server.autofill.FillResponseEventLogger.AVAILABLE_COUNT_WHEN_FILL_REQUEST_FAILED_OR_TIMEOUT;
import static com.android.server.autofill.FillResponseEventLogger.DETECTION_PREFER_AUTOFILL_PROVIDER;
import static com.android.server.autofill.FillResponseEventLogger.DETECTION_PREFER_UNKNOWN;
import static com.android.server.autofill.FillResponseEventLogger.DETECTION_PREFER_PCC;
import static com.android.server.autofill.FillResponseEventLogger.HAVE_SAVE_TRIGGER_ID;
import static com.android.server.autofill.FillResponseEventLogger.RESPONSE_STATUS_FAILURE;
import static com.android.server.autofill.FillResponseEventLogger.RESPONSE_STATUS_SESSION_DESTROYED;
@@ -1460,6 +1463,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
mFillResponseEventLogger.maybeSetRequestId(requestId);
mFillResponseEventLogger.maybeSetAppPackageUid(uid);
mFillResponseEventLogger.maybeSetResponseStatus(RESPONSE_STATUS_SUCCESS);
mFillResponseEventLogger.startResponseProcessingTime();
// Time passed since session was created
final long fillRequestReceivedRelativeTimestamp =
SystemClock.elapsedRealtime() - mLatencyBaseTime;
@@ -1467,6 +1471,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
(int) (fillRequestReceivedRelativeTimestamp));
mFillResponseEventLogger.maybeSetLatencyFillResponseReceivedMillis(
(int) (fillRequestReceivedRelativeTimestamp));
mFillResponseEventLogger.maybeSetDetectionPreference(getDetectionPreferenceForLogging());
synchronized (mLock) {
if (mDestroyed) {
@@ -1485,6 +1490,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
Slog.w(TAG, "onFillRequestSuccess(): no request log for id " + requestId);
}
if (response == null) {
mFillResponseEventLogger.maybeSetTotalDatasetsProvided(0);
if (requestLog != null) {
requestLog.addTaggedData(MetricsEvent.FIELD_AUTOFILL_NUM_DATASETS, -1);
}
@@ -1584,13 +1590,16 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
}
}
mFillResponseEventLogger.maybeSetAvailableCount(
datasetList == null ? 0 : datasetList.size());
int datasetCount = (datasetList == null) ? 0 : datasetList.size();
mFillResponseEventLogger.maybeSetTotalDatasetsProvided(datasetCount);
// It's possible that this maybe overwritten later on after PCC filtering.
mFillResponseEventLogger.maybeSetAvailableCount(datasetCount);
// TODO(b/266379948): Ideally wait for PCC request to finish for a while more
// (say 100ms) before proceeding further on.
processResponseLockedForPcc(response, response.getClientState(), requestFlags);
mFillResponseEventLogger.maybeSetLatencyResponseProcessingMillis();
}
@@ -1993,7 +2002,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
null,
dataset.getId(),
dataset.getAuthentication());
dataset.setEligibleReasonReason(pickReason);
newDataset.setEligibleReasonReason(pickReason);
eligibleDatasets.add(newDataset);
Set<Dataset> newDatasets;
for (AutofillId autofillId : datasetAutofillIds) {
@@ -2036,7 +2045,10 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
mFillResponseEventLogger.maybeSetRequestId(requestId);
mFillResponseEventLogger.maybeSetAppPackageUid(uid);
mFillResponseEventLogger.maybeSetAvailableCount(
AVAILABLE_COUNT_WHEN_FILL_REQUEST_FAILED_OR_TIMEOUT);
AVAILABLE_COUNT_WHEN_FILL_REQUEST_FAILED_OR_TIMEOUT);
mFillResponseEventLogger.maybeSetTotalDatasetsProvided(
AVAILABLE_COUNT_WHEN_FILL_REQUEST_FAILED_OR_TIMEOUT);
mFillResponseEventLogger.maybeSetDetectionPreference(getDetectionPreferenceForLogging());
final long fillRequestReceivedRelativeTimestamp =
SystemClock.elapsedRealtime() - mLatencyBaseTime;
mFillResponseEventLogger.maybeSetLatencyFillResponseReceivedMillis(
@@ -3887,8 +3899,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
// View is triggering autofill.
mCurrentViewId = viewState.id;
viewState.update(value, virtualBounds, flags);
mPresentationStatsEventLogger.startNewEvent();
mPresentationStatsEventLogger.maybeSetAutofillServiceUid(getAutofillServiceUid());
startNewEventForPresentationStatsEventLogger();
mPresentationStatsEventLogger.maybeSetIsNewRequest(true);
if (!isRequestSupportFillDialog(flags)) {
mSessionFlags.mFillDialogDisabled = true;
@@ -4021,9 +4032,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
}
// If previous request was FillDialog request, a logger event was already started
if (!wasPreviouslyFillDialog) {
mPresentationStatsEventLogger.startNewEvent();
mPresentationStatsEventLogger.maybeSetAutofillServiceUid(
getAutofillServiceUid());
startNewEventForPresentationStatsEventLogger();
}
if (requestNewFillResponseOnViewEnteredIfNecessaryLocked(id, viewState, flags)) {
// If a new request was issued even if previously it was fill dialog request,
@@ -4032,9 +4041,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
// lock guarded, we should be safe.
if (wasPreviouslyFillDialog) {
mPresentationStatsEventLogger.logAndEndEvent();
mPresentationStatsEventLogger.startNewEvent();
mPresentationStatsEventLogger.maybeSetAutofillServiceUid(
getAutofillServiceUid());
startNewEventForPresentationStatsEventLogger();
}
return;
}
@@ -4966,7 +4973,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
List<Dataset> datasetList = newResponse.getDatasets();
mPresentationStatsEventLogger.maybeSetAvailableCount(datasetList, mCurrentViewId);
mFillResponseEventLogger.maybeSetAvailableDatasetsPccCount(datasetList);
mFillResponseEventLogger.maybeSetDatasetsCountAfterPotentialPccFiltering(datasetList);
setViewStatesLocked(newResponse, ViewState.STATE_FILLABLE, false);
updateFillDialogTriggerIdsLocked();
@@ -5153,6 +5160,25 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
};
}
private int getDetectionPreferenceForLogging() {
if (mService.isPccClassificationEnabled()) {
if (mService.getMaster().preferProviderOverPcc()) {
return DETECTION_PREFER_AUTOFILL_PROVIDER;
}
return DETECTION_PREFER_PCC;
}
return DETECTION_PREFER_UNKNOWN;
}
private void startNewEventForPresentationStatsEventLogger() {
synchronized (mLock) {
mPresentationStatsEventLogger.startNewEvent();
mPresentationStatsEventLogger.maybeSetDetectionPreference(
getDetectionPreferenceForLogging());
mPresentationStatsEventLogger.maybeSetAutofillServiceUid(getAutofillServiceUid());
}
}
private void startAuthentication(int authenticationId, IntentSender intent,
Intent fillInIntent, boolean authenticateInline) {
try {