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

Adding the logging of AutofillFillRequestEvent.

Browse Source 
bug: 265051751
Test: local build
Change-Id: I4ce24df7c21bdecff46e9697b26a4f0512b84cc5
This commit is contained in:
jiewenlei
2023-03-13 10:40:03 -07:00
parent c2540fda16
commit 09730bbeb0
3 changed files with 349 additions and 15 deletions
Download Patch File Download Diff File Expand all files Collapse all files

268
services/autofill/java/com/android/server/autofill/FillRequestEventLogger.java Normal file
View File

@@ -0,0 +1,268 @@
/*
* Copyright (C) 2022 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 com.android.server.autofill;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_REQUEST_REPORTED;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_EXPLICITLY_REQUESTED;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_NORMAL_TRIGGER;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_PRE_TRIGGER;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_RETRIGGER;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_SERVED_FROM_CACHED_RESPONSE;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_UNKNOWN;
import static com.android.server.autofill.Helper.sVerbose;
import android.annotation.IntDef;
import android.content.ComponentName;
import android.content.Context;
import android.content.pm.PackageManager;
import android.provider.Settings;
import android.text.TextUtils;
import android.util.Slog;
import com.android.internal.util.FrameworkStatsLog;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.util.Optional;
/**
* Helper class to log Autofill FillRequest filing stats.
*/
public final class FillRequestEventLogger {
private static final String TAG = "FillRequestEventLogger";
/**
* Reasons why presentation was not shown. These are wrappers around
* {@link com.android.os.AtomsProto.AutofillFillRequestReported.RequestTriggerReason}.
*/
@IntDef(prefix = {"TRIGGER_REASON"}, value = {
TRIGGER_REASON_UNKNOWN,
TRIGGER_REASON_EXPLICITLY_REQUESTED,
TRIGGER_REASON_RETRIGGER,
TRIGGER_REASON_PRE_TRIGGER,
TRIGGER_REASON_NORMAL_TRIGGER,
TRIGGER_REASON_SERVED_FROM_CACHED_RESPONSE
})
@Retention(RetentionPolicy.SOURCE)
public @interface TriggerReason {
}
public static final int TRIGGER_REASON_UNKNOWN =
AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_UNKNOWN;
public static final int TRIGGER_REASON_EXPLICITLY_REQUESTED =
AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_EXPLICITLY_REQUESTED;
public static final int TRIGGER_REASON_RETRIGGER =
AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_RETRIGGER;
public static final int TRIGGER_REASON_PRE_TRIGGER =
AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_PRE_TRIGGER;
public static final int TRIGGER_REASON_NORMAL_TRIGGER =
AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_NORMAL_TRIGGER;
public static final int TRIGGER_REASON_SERVED_FROM_CACHED_RESPONSE =
AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_SERVED_FROM_CACHED_RESPONSE;
private final int mSessionId;
private Optional<FillRequestEventInternal> mEventInternal;
private FillRequestEventLogger(int sessionId) {
mSessionId = sessionId;
mEventInternal = Optional.empty();
}
/**
* A factory constructor to create FillRequestEventLogger.
*/
public static FillRequestEventLogger forSessionId(int sessionId) {
return new FillRequestEventLogger(sessionId);
}
/**
* Reset mEventInternal before logging for a new request. It shall be called for each
* FillRequest.
*/
public void startLogForNewRequest() {
if (!mEventInternal.isEmpty()) {
Slog.w(TAG, "FillRequestEventLogger is not empty before starting for a new " +
"request");
}
mEventInternal = Optional.of(new FillRequestEventInternal());
}
/**
* Set request_id as long as mEventInternal presents.
*/
public void maybeSetRequestId(int requestId) {
mEventInternal.ifPresent(event -> event.mRequestId = requestId);
}
/**
* Set service_uid as long as mEventInternal presents.
*/
public void maybeSetAutofillServiceUid(int uid) {
mEventInternal.ifPresent(event -> {
event.mAutofillServiceUid = uid;
});
}
/**
* Set inline_suggestion_host_uid as long as mEventInternal presents.
*/
public void maybeSetInlineSuggestionHostUid(Context context, int userId) {
mEventInternal.ifPresent(event -> {
String imeString = Settings.Secure.getStringForUser(context.getContentResolver(),
Settings.Secure.DEFAULT_INPUT_METHOD, userId);
if (TextUtils.isEmpty(imeString)) {
Slog.w(TAG, "No default IME found");
return;
}
ComponentName imeComponent = ComponentName.unflattenFromString(imeString);
if (imeComponent == null) {
Slog.w(TAG, "No default IME found");
return;
}
int imeUid;
String packageName = imeComponent.getPackageName();
try {
imeUid = context.getPackageManager().getApplicationInfoAsUser(packageName,
PackageManager.ApplicationInfoFlags.of(0), userId).uid;
} catch (PackageManager.NameNotFoundException e) {
Slog.w(TAG, "Couldn't find packageName: " + packageName);
return;
}
event.mInlineSuggestionHostUid = imeUid;
});
}
/**
* Set flags as long as mEventInternal presents.
*/
public void maybeSetFlags(int flags) {
mEventInternal.ifPresent(event -> {
event.mFlags = flags;
});
}
/**
* Set request_trigger_reason as long as mEventInternal presents.
*/
public void maybeSetRequestTriggerReason(@TriggerReason int reason) {
mEventInternal.ifPresent(event -> {
event.mRequestTriggerReason = reason;
});
}
/**
* Set is_augmented as long as mEventInternal presents.
*/
public void maybeSetIsAugmented(boolean val) {
mEventInternal.ifPresent(event -> {
event.mIsAugmented = val;
});
}
/**
* Set is_client_suggestion as long as mEventInternal presents.
*/
public void maybeSetIsClientSuggestionFallback(boolean val) {
mEventInternal.ifPresent(event -> {
event.mIsClientSuggestionFallback = val;
});
}
/**
* Set is_fill_dialog_eligible as long as mEventInternal presents.
*/
public void maybeSetIsFillDialogEligible(boolean val) {
mEventInternal.ifPresent(event -> {
event.mIsFillDialogEligible = val;
});
}
/**
* Set latency_fill_request_sent_millis as long as mEventInternal presents.
*/
public void maybeSetLatencyFillRequestSentMillis(int timestamp) {
mEventInternal.ifPresent(event -> {
event.mLatencyFillRequestSentMillis = timestamp;
});
}
/**
* Set app_package_uid as long as mEventInternal presents.
*/
public void maybeSetAppPackageUid(int uid) {
mEventInternal.ifPresent(event -> {
event.mAppPackageUid = uid;
});
}
/**
* Log an AUTOFILL_FILL_REQUEST_REPORTED event.
*/
public void logAndEndEvent() {
if (!mEventInternal.isPresent()) {
Slog.w(TAG, "Shouldn't be logging AutofillFillRequestReported again for same "
+ "event");
return;
}
FillRequestEventInternal event = mEventInternal.get();
if (sVerbose) {
Slog.v(TAG, "Log AutofillFillRequestReported:"
+ " requestId=" + event.mRequestId
+ " sessionId=" + mSessionId
+ " mAutofillServiceUid=" + event.mAutofillServiceUid
+ " mInlineSuggestionHostUid=" + event.mInlineSuggestionHostUid
+ " mIsAugmented=" + event.mIsAugmented
+ " mIsClientSuggestionFallback=" + event.mIsClientSuggestionFallback
+ " mIsFillDialogEligible=" + event.mIsFillDialogEligible
+ " mRequestTriggerReason=" + event.mRequestTriggerReason
+ " mFlags=" + event.mFlags
+ " mLatencyFillRequestSentMillis=" + event.mLatencyFillRequestSentMillis
+ " mAppPackageUid=" + event.mAppPackageUid);
}
FrameworkStatsLog.write(
AUTOFILL_FILL_REQUEST_REPORTED,
event.mRequestId,
mSessionId,
event.mAutofillServiceUid,
event.mInlineSuggestionHostUid,
event.mIsAugmented,
event.mIsClientSuggestionFallback,
event.mIsFillDialogEligible,
event.mRequestTriggerReason,
event.mFlags,
event.mLatencyFillRequestSentMillis,
event.mAppPackageUid);
mEventInternal = Optional.empty();
}
private static final class FillRequestEventInternal {
int mRequestId;
int mAppPackageUid = -1;
int mAutofillServiceUid = -1;
int mInlineSuggestionHostUid = -1;
boolean mIsAugmented = false;
boolean mIsClientSuggestionFallback = false;
boolean mIsFillDialogEligible = false;
int mRequestTriggerReason =
AUTOFILL_FILL_REQUEST_REPORTED__REQUEST_TRIGGER_REASON__TRIGGER_REASON_UNKNOWN;
int mFlags = -1;
int mLatencyFillRequestSentMillis = -1;
FillRequestEventInternal() {
}
}
}

55
services/autofill/java/com/android/server/autofill/PresentationStatsEventLogger.java
View File

@@ -38,6 +38,7 @@ import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_SESSION_COMMITTED_PREMATURELY;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_UNKNOWN_REASON;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_VIEW_CHANGED;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_VIEW_FOCUSED_BEFORE_FILL_DIALOG_RESPONSE;
import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_VIEW_FOCUS_CHANGED;
import static com.android.server.autofill.Helper.sVerbose;
@@ -71,6 +72,7 @@ public final class PresentationStatsEventLogger {
@IntDef(prefix = {"NOT_SHOWN_REASON"}, value = {
NOT_SHOWN_REASON_ANY_SHOWN,
NOT_SHOWN_REASON_VIEW_FOCUS_CHANGED,
NOT_SHOWN_REASON_VIEW_FOCUSED_BEFORE_FILL_DIALOG_RESPONSE,
NOT_SHOWN_REASON_VIEW_CHANGED,
NOT_SHOWN_REASON_ACTIVITY_FINISHED,
NOT_SHOWN_REASON_REQUEST_TIMEOUT,
@@ -86,6 +88,8 @@ public final class PresentationStatsEventLogger {
AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__ANY_SHOWN;
public static final int NOT_SHOWN_REASON_VIEW_FOCUS_CHANGED =
AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_VIEW_FOCUS_CHANGED;
public static final int NOT_SHOWN_REASON_VIEW_FOCUSED_BEFORE_FILL_DIALOG_RESPONSE =
AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_VIEW_FOCUSED_BEFORE_FILL_DIALOG_RESPONSE;
public static final int NOT_SHOWN_REASON_VIEW_CHANGED =
AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_VIEW_CHANGED;
public static final int NOT_SHOWN_REASON_ACTIVITY_FINISHED =
@@ -142,7 +146,7 @@ public final class PresentationStatsEventLogger {
}
public void maybeSetAvailableCount(@Nullable List<Dataset> datasetList,
AutofillId currentViewId) {
AutofillId currentViewId) {
mEventInternal.ifPresent(event -> {
int availableCount = getDatasetCountForAutofillId(datasetList, currentViewId);
event.mAvailableCount = availableCount;
@@ -151,7 +155,7 @@ public final class PresentationStatsEventLogger {
}
public void maybeSetCountShown(@Nullable List<Dataset> datasetList,
AutofillId currentViewId) {
AutofillId currentViewId) {
mEventInternal.ifPresent(event -> {
int countShown = getDatasetCountForAutofillId(datasetList, currentViewId);
event.mCountShown = countShown;
@@ -162,7 +166,7 @@ public final class PresentationStatsEventLogger {
}
private static int getDatasetCountForAutofillId(@Nullable List<Dataset> datasetList,
AutofillId currentViewId) {
AutofillId currentViewId) {
int availableCount = 0;
if (datasetList != null) {
for (int i = 0; i < datasetList.size(); i++) {
@@ -225,10 +229,34 @@ public final class PresentationStatsEventLogger {
});
}
public void maybeSetSelectedDatasetId(int selectedDatasetId) {
mEventInternal.ifPresent(event -> {
event.mSelectedDatasetId = selectedDatasetId;
});
}
public void maybeSetDialogDismissed(boolean dialogDismissed) {
mEventInternal.ifPresent(event -> {
event.mDialogDismissed = dialogDismissed;
});
}
public void maybeSetNegativeCtaButtonClicked(boolean negativeCtaButtonClicked) {
mEventInternal.ifPresent(event -> {
event.mNegativeCtaButtonClicked = negativeCtaButtonClicked;
});
}
public void maybeSetPositiveCtaButtonClicked(boolean positiveCtaButtonClicked) {
mEventInternal.ifPresent(event -> {
event.mPositiveCtaButtonClicked = positiveCtaButtonClicked;
});
}
public void maybeSetInlinePresentationAndSuggestionHostUid(Context context, int userId) {
mEventInternal.ifPresent(event -> {
event.mDisplayPresentationType =
AUTOFILL_PRESENTATION_EVENT_REPORTED__DISPLAY_PRESENTATION_TYPE__INLINE;
AUTOFILL_PRESENTATION_EVENT_REPORTED__DISPLAY_PRESENTATION_TYPE__INLINE;
String imeString = Settings.Secure.getStringForUser(context.getContentResolver(),
Settings.Secure.DEFAULT_INPUT_METHOD, userId);
if (TextUtils.isEmpty(imeString)) {
@@ -290,7 +318,11 @@ public final class PresentationStatsEventLogger {
+ " mFillRequestSentTimestampMs=" + event.mFillRequestSentTimestampMs
+ " mFillResponseReceivedTimestampMs=" + event.mFillResponseReceivedTimestampMs
+ " mSuggestionSentTimestampMs=" + event.mSuggestionSentTimestampMs
+ " mSuggestionPresentedTimestampMs=" + event.mSuggestionPresentedTimestampMs);
+ " mSuggestionPresentedTimestampMs=" + event.mSuggestionPresentedTimestampMs
+ " mSelectedDatasetId=" + event.mSelectedDatasetId
+ " mDialogDismissed=" + event.mDialogDismissed
+ " mNegativeCtaButtonClicked=" + event.mNegativeCtaButtonClicked
+ " mPositiveCtaButtonClicked=" + event.mPositiveCtaButtonClicked);
}
// TODO(b/234185326): Distinguish empty responses from other no presentation reasons.
@@ -316,11 +348,10 @@ public final class PresentationStatsEventLogger {
event.mFillResponseReceivedTimestampMs,
event.mSuggestionSentTimestampMs,
event.mSuggestionPresentedTimestampMs,
//TODO(b/265051751): add new framework logging.
/* selected_dataset_id= */ 0,
/* dialog_dismissed= */ false,
/* negative_cta_button_clicked= */ false,
/* positive_cta_button_clicked= */ false);
event.mSelectedDatasetId,
event.mDialogDismissed,
event.mNegativeCtaButtonClicked,
event.mPositiveCtaButtonClicked);
mEventInternal = Optional.empty();
}
@@ -341,6 +372,10 @@ public final class PresentationStatsEventLogger {
int mFillResponseReceivedTimestampMs;
int mSuggestionSentTimestampMs;
int mSuggestionPresentedTimestampMs;
int mSelectedDatasetId = -1;
boolean mDialogDismissed = false;
boolean mNegativeCtaButtonClicked = false;
boolean mPositiveCtaButtonClicked = false;
PresentationStatsEventInternal() {}
}

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

@@ -40,6 +40,9 @@ import static android.view.autofill.AutofillManager.FLAG_SMART_SUGGESTION_SYSTEM
import static android.view.autofill.AutofillManager.getSmartSuggestionModeToString;
import static com.android.internal.util.function.pooled.PooledLambda.obtainMessage;
import static com.android.server.autofill.FillRequestEventLogger.TRIGGER_REASON_NORMAL_TRIGGER;
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.Helper.containsCharsInOrder;
import static com.android.server.autofill.Helper.createSanitizers;
import static com.android.server.autofill.Helper.getNumericValue;
@@ -437,6 +440,10 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
@GuardedBy("mLock")
private PresentationStatsEventLogger mPresentationStatsEventLogger;
@NonNull
@GuardedBy("mLock")
private FillRequestEventLogger mFillRequestEventLogger;
/**
* Fill dialog request would likely be sent slightly later.
*/
@@ -603,6 +610,14 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
mPendingInlineSuggestionsRequest = null;
mWaitForInlineRequest = false;
mPendingFillRequest = null;
final long fillRequestSentRelativeTimestamp =
SystemClock.elapsedRealtime() - mLatencyBaseTime;
mPresentationStatsEventLogger.maybeSetFillRequestSentTimestampMs(
(int) (fillRequestSentRelativeTimestamp));
mFillRequestEventLogger.maybeSetLatencyFillRequestSentMillis(
(int) (fillRequestSentRelativeTimestamp));
mFillRequestEventLogger.logAndEndEvent();
}
@Override
@@ -1080,11 +1095,21 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
private void requestNewFillResponseLocked(@NonNull ViewState viewState, int newState,
int flags) {
final FillResponse existingResponse = viewState.getResponse();
mFillRequestEventLogger.startLogForNewRequest();
mFillRequestEventLogger.maybeSetAppPackageUid(uid);
mFillRequestEventLogger.maybeSetFlags(mFlags);
if(mPreviouslyFillDialogPotentiallyStarted) {
mFillRequestEventLogger.maybeSetRequestTriggerReason(TRIGGER_REASON_PRE_TRIGGER);
} else {
mFillRequestEventLogger.maybeSetRequestTriggerReason(TRIGGER_REASON_NORMAL_TRIGGER);
}
if (existingResponse != null) {
setViewStatesLocked(
existingResponse,
ViewState.STATE_INITIAL,
/* clearResponse= */ true);
mFillRequestEventLogger.maybeSetRequestTriggerReason(
TRIGGER_REASON_SERVED_FROM_CACHED_RESPONSE);
}
mSessionFlags.mExpiredResponse = false;
mSessionState = STATE_ACTIVE;
@@ -1095,6 +1120,10 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
+ ", flags=" + flags + ")");
}
mSessionFlags.mAugmentedAutofillOnly = true;
// Augmented autofill doesn't have request_id.
mFillRequestEventLogger.maybeSetRequestId(-1);
mFillRequestEventLogger.maybeSetIsAugmented(mSessionFlags.mAugmentedAutofillOnly);
mFillRequestEventLogger.logAndEndEvent();
triggerAugmentedAutofillLocked(flags);
return;
}
@@ -1121,6 +1150,12 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
+ ", flags=" + flags);
}
mPresentationStatsEventLogger.maybeSetRequestId(requestId);
mFillRequestEventLogger.maybeSetRequestId(requestId);
mFillRequestEventLogger.maybeSetAutofillServiceUid(getAutofillServiceUid());
if (mSessionFlags.mInlineSupportedByService) {
mFillRequestEventLogger.maybeSetInlineSuggestionHostUid(mContext, userId);
}
mFillRequestEventLogger.maybeSetIsFillDialogEligible(!mSessionFlags.mFillDialogDisabled);
// If the focus changes very quickly before the first request is returned each focus change
// triggers a new partition and we end up with many duplicate partitions. This is
@@ -1187,11 +1222,6 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
return;
}
final long fillRequestSentRelativeTimestamp =
SystemClock.elapsedRealtime() - mLatencyBaseTime;
mPresentationStatsEventLogger.maybeSetFillRequestSentTimestampMs(
(int) (fillRequestSentRelativeTimestamp));
// Now request the assist structure data.
requestAssistStructureLocked(requestId, flags);
}
@@ -1282,6 +1312,7 @@ final class Session implements RemoteFillService.FillServiceCallbacks, ViewState
mCompatMode = compatMode;
mSessionState = STATE_ACTIVE;
mPresentationStatsEventLogger = PresentationStatsEventLogger.forSessionId(sessionId);
mFillRequestEventLogger = FillRequestEventLogger.forSessionId(sessionId);
synchronized (mLock) {
mSessionFlags = new SessionFlags();
mSessionFlags.mAugmentedAutofillOnly = forAugmentedAutofillOnly;