Merge "[logging] Log pre-trigger removal related info to measure its impact on... (7a096d3f) · Commits · e / os / android_frameworks_base

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

+96 −4

Original line number	Diff line number	Diff line
		@@ -39,6 +39,14 @@ import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__DISPLAY_PRESENTATION_TYPE__INLINE;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__DISPLAY_PRESENTATION_TYPE__MENU;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__DISPLAY_PRESENTATION_TYPE__UNKNOWN_AUTOFILL_DISPLAY_PRESENTATION_TYPE;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_DELAY_AFTER_ANIMATION_END;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_FILL_DIALOG_DISABLED;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_LAST_TRIGGERED_ID_CHANGED;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_SCREEN_HAS_CREDMAN_FIELD;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_TIMEOUT_AFTER_DELAY;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_TIMEOUT_SINCE_IME_ANIMATED;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_UNKNOWN;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_WAIT_FOR_IME_ANIMATION;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__ANY_SHOWN;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_ACTIVITY_FINISHED;
		import static com.android.internal.util.FrameworkStatsLog.AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__NONE_SHOWN_FILL_REQUEST_FAILED;
		@@ -157,8 +165,24 @@ public final class PresentationStatsEventLogger {
		DETECTION_PREFER_PCC
		})
		@Retention(RetentionPolicy.SOURCE)
		public @interface DetectionPreference {
		}
		public @interface DetectionPreference {}

		/**
		* The fill dialog not shown reason. These are wrappers around
		* {@link com.android.os.AtomsProto.AutofillPresentationEventReported.FillDialogNotShownReason}.
		*/
		@IntDef(prefix = {"FILL_DIALOG_NOT_SHOWN_REASON"}, value = {
		FILL_DIALOG_NOT_SHOWN_REASON_UNKNOWN,
		FILL_DIALOG_NOT_SHOWN_REASON_FILL_DIALOG_DISABLED,
		FILL_DIALOG_NOT_SHOWN_REASON_SCREEN_HAS_CREDMAN_FIELD,
		FILL_DIALOG_NOT_SHOWN_REASON_LAST_TRIGGERED_ID_CHANGED,
		FILL_DIALOG_NOT_SHOWN_REASON_WAIT_FOR_IME_ANIMATION,
		FILL_DIALOG_NOT_SHOWN_REASON_TIMEOUT_SINCE_IME_ANIMATED,
		FILL_DIALOG_NOT_SHOWN_REASON_DELAY_AFTER_ANIMATION_END,
		FILL_DIALOG_NOT_SHOWN_REASON_TIMEOUT_AFTER_DELAY
		})
		@Retention(RetentionPolicy.SOURCE)
		public @interface FillDialogNotShownReason {}

		public static final int NOT_SHOWN_REASON_ANY_SHOWN =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__PRESENTATION_EVENT_RESULT__ANY_SHOWN;
		@@ -219,6 +243,25 @@ public final class PresentationStatsEventLogger {
		public static final int DETECTION_PREFER_PCC =
		AUTOFILL_FILL_RESPONSE_REPORTED__DETECTION_PREFERENCE__DETECTION_PREFER_PCC;

		// Values for AutofillFillResponseReported.fill_dialog_not_shown_reason
		public static final int FILL_DIALOG_NOT_SHOWN_REASON_UNKNOWN =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_UNKNOWN;
		public static final int FILL_DIALOG_NOT_SHOWN_REASON_FILL_DIALOG_DISABLED =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_FILL_DIALOG_DISABLED;
		public static final int FILL_DIALOG_NOT_SHOWN_REASON_SCREEN_HAS_CREDMAN_FIELD =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_SCREEN_HAS_CREDMAN_FIELD;
		public static final int FILL_DIALOG_NOT_SHOWN_REASON_LAST_TRIGGERED_ID_CHANGED =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_LAST_TRIGGERED_ID_CHANGED;
		public static final int FILL_DIALOG_NOT_SHOWN_REASON_WAIT_FOR_IME_ANIMATION =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_WAIT_FOR_IME_ANIMATION;
		public static final int FILL_DIALOG_NOT_SHOWN_REASON_TIMEOUT_SINCE_IME_ANIMATED =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_TIMEOUT_SINCE_IME_ANIMATED;
		public static final int FILL_DIALOG_NOT_SHOWN_REASON_DELAY_AFTER_ANIMATION_END =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_DELAY_AFTER_ANIMATION_END;
		public static final int FILL_DIALOG_NOT_SHOWN_REASON_TIMEOUT_AFTER_DELAY =
		AUTOFILL_PRESENTATION_EVENT_REPORTED__FILL_DIALOG_NOT_SHOWN_REASON__REASON_TIMEOUT_AFTER_DELAY;


		private static final int DEFAULT_VALUE_INT = -1;

		private final int mSessionId;
		@@ -870,6 +913,43 @@ public final class PresentationStatsEventLogger {
		});
		}

		/**
		* Set fill_dialog_not_shown_reason
		* @param reason
		*/
		public void maybeSetFillDialogNotShownReason(@FillDialogNotShownReason int reason) {
		mEventInternal.ifPresent(event -> {
		if ((event.mFillDialogNotShownReason
		== FILL_DIALOG_NOT_SHOWN_REASON_DELAY_AFTER_ANIMATION_END
		\|\| event.mFillDialogNotShownReason
		== FILL_DIALOG_NOT_SHOWN_REASON_WAIT_FOR_IME_ANIMATION) && reason
		== FILL_DIALOG_NOT_SHOWN_REASON_TIMEOUT_SINCE_IME_ANIMATED) {
		event.mFillDialogNotShownReason = FILL_DIALOG_NOT_SHOWN_REASON_TIMEOUT_AFTER_DELAY;
		} else {
		event.mFillDialogNotShownReason = reason;
		}
		});
		}

		/**
		* Set fill_dialog_ready_to_show_ms
		* @param val
		*/
		public void maybeSetFillDialogReadyToShowMs(long val) {
		mEventInternal.ifPresent(event -> {
		event.mFillDialogReadyToShowMs = (int) (val - mSessionStartTimestamp);
		});
		}

		/**
		* Set ime_animation_finish_ms
		* @param val
		*/
		public void maybeSetImeAnimationFinishMs(long val) {
		mEventInternal.ifPresent(event -> {
		event.mImeAnimationFinishMs = (int) (val - mSessionStartTimestamp);
		});
		}
		/**
		* Set the log contains relayout metrics.
		* This is being added as a temporary measure to add logging.
		@@ -959,7 +1039,13 @@ public final class PresentationStatsEventLogger {
		+ " event.notExpiringResponseDuringAuthCount="
		+ event.mFixExpireResponseDuringAuthCount
		+ " event.notifyViewEnteredIgnoredDuringAuthCount="
		+ event.mNotifyViewEnteredIgnoredDuringAuthCount);
		+ event.mNotifyViewEnteredIgnoredDuringAuthCount
		+ " event.fillDialogNotShownReason="
		+ event.mFillDialogNotShownReason
		+ " event.fillDialogReadyToShowMs="
		+ event.mFillDialogReadyToShowMs
		+ " event.imeAnimationFinishMs="
		+ event.mImeAnimationFinishMs);
		}

		// TODO(b/234185326): Distinguish empty responses from other no presentation reasons.
		@@ -1020,7 +1106,10 @@ public final class PresentationStatsEventLogger {
		event.mViewFilledSuccessfullyOnRefillCount,
		event.mViewFailedOnRefillCount,
		event.mFixExpireResponseDuringAuthCount,
		event.mNotifyViewEnteredIgnoredDuringAuthCount);
		event.mNotifyViewEnteredIgnoredDuringAuthCount,
		event.mFillDialogNotShownReason,
		event.mFillDialogReadyToShowMs,
		event.mImeAnimationFinishMs);
		mEventInternal = Optional.empty();
		}

		@@ -1087,6 +1176,9 @@ public final class PresentationStatsEventLogger {
		// Following are not logged and used only for internal logic
		boolean shouldResetShownCount = false;
		boolean mHasRelayoutLog = false;
		@FillDialogNotShownReason int mFillDialogNotShownReason = FILL_DIALOG_NOT_SHOWN_REASON_UNKNOWN;
		int mFillDialogReadyToShowMs = DEFAULT_VALUE_INT;
		int mImeAnimationFinishMs = DEFAULT_VALUE_INT;
		PresentationStatsEventInternal() {}
		}

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

+32 −0

Original line number	Diff line number	Diff line
		@@ -81,6 +81,13 @@ import static com.android.server.autofill.PresentationStatsEventLogger.AUTHENTIC
		import static com.android.server.autofill.PresentationStatsEventLogger.AUTHENTICATION_RESULT_SUCCESS;
		import static com.android.server.autofill.PresentationStatsEventLogger.AUTHENTICATION_TYPE_DATASET_AUTHENTICATION;
		import static com.android.server.autofill.PresentationStatsEventLogger.AUTHENTICATION_TYPE_FULL_AUTHENTICATION;
		import static com.android.server.autofill.PresentationStatsEventLogger.FILL_DIALOG_NOT_SHOWN_REASON_DELAY_AFTER_ANIMATION_END;
		import static com.android.server.autofill.PresentationStatsEventLogger.FILL_DIALOG_NOT_SHOWN_REASON_FILL_DIALOG_DISABLED;
		import static com.android.server.autofill.PresentationStatsEventLogger.FILL_DIALOG_NOT_SHOWN_REASON_LAST_TRIGGERED_ID_CHANGED;
		import static com.android.server.autofill.PresentationStatsEventLogger.FILL_DIALOG_NOT_SHOWN_REASON_SCREEN_HAS_CREDMAN_FIELD;
		import static com.android.server.autofill.PresentationStatsEventLogger.FILL_DIALOG_NOT_SHOWN_REASON_TIMEOUT_SINCE_IME_ANIMATED;
		import static com.android.server.autofill.PresentationStatsEventLogger.FILL_DIALOG_NOT_SHOWN_REASON_UNKNOWN;
		import static com.android.server.autofill.PresentationStatsEventLogger.FILL_DIALOG_NOT_SHOWN_REASON_WAIT_FOR_IME_ANIMATION;
		import static com.android.server.autofill.PresentationStatsEventLogger.NOT_SHOWN_REASON_ANY_SHOWN;
		import static com.android.server.autofill.PresentationStatsEventLogger.NOT_SHOWN_REASON_NO_FOCUS;
		import static com.android.server.autofill.PresentationStatsEventLogger.NOT_SHOWN_REASON_REQUEST_FAILED;
		@@ -5622,6 +5629,10 @@ final class Session
		synchronized (mLock) {
		final ViewState currentView = mViewStates.get(mCurrentViewId);
		currentView.setState(ViewState.STATE_FILL_DIALOG_SHOWN);
		// Set fill_dialog_not_shown_reason to unknown (a.k.a shown). It is needed due
		// to possible SHOW_FILL_DIALOG_WAIT.
		mPresentationStatsEventLogger.maybeSetFillDialogNotShownReason(
		FILL_DIALOG_NOT_SHOWN_REASON_UNKNOWN);
		}
		// Just show fill dialog once per fill request, so disabled after shown.
		// Note: Cannot disable before requestShowFillDialog() because the method
		@@ -5725,6 +5736,15 @@ final class Session

		private boolean isFillDialogUiEnabled() {
		synchronized (mLock) {
		if (mSessionFlags.mFillDialogDisabled) {
		mPresentationStatsEventLogger.maybeSetFillDialogNotShownReason(
		FILL_DIALOG_NOT_SHOWN_REASON_FILL_DIALOG_DISABLED);
		}
		if (mSessionFlags.mScreenHasCredmanField) {
		// Prefer to log "HAS_CREDMAN_FIELD" over "FILL_DIALOG_DISABLED".
		mPresentationStatsEventLogger.maybeSetFillDialogNotShownReason(
		FILL_DIALOG_NOT_SHOWN_REASON_SCREEN_HAS_CREDMAN_FIELD);
		}
		return !mSessionFlags.mFillDialogDisabled && !mSessionFlags.mScreenHasCredmanField;
		}
		}
		@@ -5789,6 +5809,8 @@ final class Session
		\|\| !ArrayUtils.contains(mLastFillDialogTriggerIds, filledId)) {
		// Last fill dialog triggered ids are changed.
		if (sDebug) Log.w(TAG, "Last fill dialog triggered ids are changed.");
		mPresentationStatsEventLogger.maybeSetFillDialogNotShownReason(
		FILL_DIALOG_NOT_SHOWN_REASON_LAST_TRIGGERED_ID_CHANGED);
		return SHOW_FILL_DIALOG_NO;
		}

		@@ -5815,6 +5837,8 @@ final class Session
		// we need to wait for animation to happen. We can't return from here yet.
		// This is the situation #2 described above.
		Log.d(TAG, "Waiting for ime animation to complete before showing fill dialog");
		mPresentationStatsEventLogger.maybeSetFillDialogNotShownReason(
		FILL_DIALOG_NOT_SHOWN_REASON_WAIT_FOR_IME_ANIMATION);
		mFillDialogRunnable = createFillDialogEvalRunnable(
		response, filledId, filterText, flags);
		return SHOW_FILL_DIALOG_WAIT;
		@@ -5824,9 +5848,15 @@ final class Session
		// max of start input time or the ime finish time
		long effectiveDuration = currentTimestampMs
		- Math.max(mLastInputStartTime, mImeAnimationFinishTimeMs);
		mPresentationStatsEventLogger.maybeSetFillDialogReadyToShowMs(
		currentTimestampMs);
		mPresentationStatsEventLogger.maybeSetImeAnimationFinishMs(
		Math.max(mLastInputStartTime, mImeAnimationFinishTimeMs));
		if (effectiveDuration >= mFillDialogTimeoutMs) {
		Log.d(TAG, "Fill dialog not shown since IME has been up for more time than "
		+ mFillDialogTimeoutMs + "ms");
		mPresentationStatsEventLogger.maybeSetFillDialogNotShownReason(
		FILL_DIALOG_NOT_SHOWN_REASON_TIMEOUT_SINCE_IME_ANIMATED);
		return SHOW_FILL_DIALOG_NO;
		} else if (effectiveDuration < mFillDialogMinWaitAfterImeAnimationMs) {
		// we need to wait for some time after animation ends
		@@ -5834,6 +5864,8 @@ final class Session
		response, filledId, filterText, flags);
		mHandler.postDelayed(runnable,
		mFillDialogMinWaitAfterImeAnimationMs - effectiveDuration);
		mPresentationStatsEventLogger.maybeSetFillDialogNotShownReason(
		FILL_DIALOG_NOT_SHOWN_REASON_DELAY_AFTER_ANIMATION_END);
		return SHOW_FILL_DIALOG_WAIT;
		}
		}