diff options
3 files changed, 349 insertions, 15 deletions
diff --git a/services/autofill/java/com/android/server/autofill/FillRequestEventLogger.java b/services/autofill/java/com/android/server/autofill/FillRequestEventLogger.java new file mode 100644 index 000000000000..3b30af69d02b --- /dev/null +++ b/services/autofill/java/com/android/server/autofill/FillRequestEventLogger.java @@ -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() { + } + } +} diff --git a/services/autofill/java/com/android/server/autofill/PresentationStatsEventLogger.java b/services/autofill/java/com/android/server/autofill/PresentationStatsEventLogger.java index 590f472e8b22..7d1de40c7150 100644 --- a/services/autofill/java/com/android/server/autofill/PresentationStatsEventLogger.java +++ b/services/autofill/java/com/android/server/autofill/PresentationStatsEventLogger.java @@ -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() {} } diff --git a/services/autofill/java/com/android/server/autofill/Session.java b/services/autofill/java/com/android/server/autofill/Session.java index 15a533c9958e..4acdabec92f4 100644 --- a/services/autofill/java/com/android/server/autofill/Session.java +++ b/services/autofill/java/com/android/server/autofill/Session.java @@ -41,6 +41,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; @@ -439,6 +442,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. */ @@ -605,6 +612,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 @@ -1082,11 +1097,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; @@ -1097,6 +1122,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; } @@ -1123,6 +1152,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 @@ -1189,11 +1224,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); } @@ -1284,6 +1314,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; |