Merge "Adding the logging of AutofillFillRequestEvent." into udc-dev am: c333c01a92 am: c92b919e7b (3e17ded3) · Commits · e / os / android_frameworks_base

services/autofill/java/com/android/server/autofill/FillRequestEventLogger.java

0 → 100644

+268 −0

Original line number	Diff line number	Diff line
		/*
		* 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() {
		}
		}
		}

services/autofill/java/com/android/server/autofill/PresentationStatsEventLogger.java

+45 −10

Original line number	Diff line number	Diff line
		@@ -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 =
		@@ -225,6 +229,30 @@ 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 =
		@@ -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() {}
		}

services/autofill/java/com/android/server/autofill/Session.java

+36 −5

Original line number	Diff line number	Diff line
		@@ -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;