Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 4ce91c01 authored by Cosmin Băieș's avatar Cosmin Băieș Committed by Felix Stern
Browse files

Use SystemClock.elapsedRealtime in ImeTracker 

Currently ImeTrackerService uses System.currentTimeMillis for the start
and finish time of the requests. However, this could break if the system
wall time is changed (by the user) between a request start and finish.

This also passes the elapsedRealtime value, to be used for the start and
finish timestamps. The currentTimeMillis is kept for convenience in
reading the history in the dumpsys, for the start and last progress
times.

Flag: EXEMPT bugfix
Test: atest ImeTrackerServiceTest
  checking output of adb shell dumpsys input_method
Bug: 342111149
Change-Id: I3e41de1c3df21ba393379b6fd6eab9cd0916ca99
parent d8180425

core/java/android/view/inputmethod/IInputMethodManagerGlobalInvoker.java

+6 −2
Original line number Diff line number Diff line
@@ -18,7 +18,9 @@ package android.view.inputmethod; 


import android.Manifest;

import android.annotation.AnyThread;

import android.annotation.CurrentTimeMillisLong;

import android.annotation.DurationMillisLong;

import android.annotation.ElapsedRealtimeLong;

import android.annotation.NonNull;

import android.annotation.Nullable;

import android.annotation.RequiresNoPermission;
@@ -617,13 +619,15 @@ final class IInputMethodManagerGlobalInvoker { 
    @AnyThread

    static void onStart(@NonNull ImeTracker.Token statsToken, int uid, @ImeTracker.Type int type,

            @ImeTracker.Origin int origin, @SoftInputShowHideReason int reason, boolean fromUser,

            long startTime) {

            @CurrentTimeMillisLong long startWallTimeMs,

            @ElapsedRealtimeLong long startTimestampMs) {

        final var service = getImeTrackerService();

        if (service == null) {

            return;

        }

        try {

            service.onStart(statsToken, uid, type, origin, reason, fromUser, startTime);

            service.onStart(statsToken, uid, type, origin, reason, fromUser, startWallTimeMs,

                    startTimestampMs);

        } catch (RemoteException e) {

            throw e.rethrowFromSystemServer();

        }

core/java/android/view/inputmethod/ImeTracker.java

+4 −2
Original line number Diff line number Diff line
@@ -33,6 +33,7 @@ import android.content.Context; 
import android.os.Parcel;

import android.os.Parcelable;

import android.os.Process;

import android.os.SystemClock;

import android.os.SystemProperties;

import android.text.TextUtils;

import android.util.Log;
@@ -631,9 +632,10 @@ public interface ImeTracker { 
        public Token onStart(@NonNull String component, int uid, @Type int type, @Origin int origin,

                @SoftInputShowHideReason int reason, boolean fromUser) {

            final var token = Token.createToken(component);

            final long startTime = System.currentTimeMillis();

            final long startWallTimeMs = System.currentTimeMillis();

            final long startTimestampMs = SystemClock.elapsedRealtime();

            IInputMethodManagerGlobalInvoker.onStart(token, uid, type,

                    origin, reason, fromUser, startTime);

                    origin, reason, fromUser, startWallTimeMs, startTimestampMs);



            log("%s: %s at %s reason %s fromUser %s%s", token.mTag,

                    getOnStartPrefix(type), Debug.originToString(origin),

core/java/com/android/internal/inputmethod/IImeTracker.aidl

+3 −2
Original line number Diff line number Diff line
@@ -35,10 +35,11 @@ oneway interface IImeTracker { 
     * @param origin the origin of the request.

     * @param reason the reason for starting the request.

     * @param fromUser whether this request was created directly from user interaction.

     * @param startTime the time in milliseconds when the request was started.

     * @param startWallTimeMs the wall time in milliseconds when the request was started.

     * @param startTimestampMs the time since boot in milliseconds when the request was started.

     */

    void onStart(in ImeTracker.Token statsToken, int uid, int type, int origin, int reason,

        boolean fromUser, long startTime);

        boolean fromUser, long startWallTimeMs, long startTimestampMs);



    /**

     * Called when the IME request progresses to a further phase.

services/core/java/com/android/server/inputmethod/ImeTrackerService.java

+47 −29
Original line number Diff line number Diff line
@@ -19,11 +19,14 @@ package com.android.server.inputmethod; 
import static android.view.ViewProtoLogGroups.IME_TRACKER;



import android.Manifest;

import android.annotation.CurrentTimeMillisLong;

import android.annotation.DurationMillisLong;

import android.annotation.ElapsedRealtimeLong;

import android.annotation.EnforcePermission;

import android.annotation.NonNull;

import android.annotation.Nullable;

import android.os.Handler;

import android.os.SystemClock;

import android.text.TextUtils;

import android.util.Log;

import android.view.inputmethod.ImeTracker;
@@ -116,7 +119,8 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
    @Override

    public void onStart(@NonNull ImeTracker.Token statsToken, int uid, @ImeTracker.Type int type,

            @ImeTracker.Origin int origin, @SoftInputShowHideReason int reason, boolean fromUser,

            long startTime) {

            @CurrentTimeMillisLong long startWallTimeMs,

            @ElapsedRealtimeLong long startTimestampMs) {

        synchronized (mLock) {

            final long id = statsToken.getId();

            final String tag = statsToken.getTag();
@@ -133,7 +137,8 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
                    return;

                }



                entry.onStart(tag, uid, type, origin, reason, fromUser, startTime);

                entry.onStart(tag, uid, type, origin, reason, fromUser, startWallTimeMs,

                        startTimestampMs);



                if (entry.mFinished) {

                    complete(id, entry);
@@ -145,9 +150,10 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
                }



                final var newEntry = new History.Entry();

                // Prefer current time to startTime when creating the entry in onStart.

                // Prefer current time to passed in startTime when creating the entry in onStart.

                newEntry.onStart(tag, uid, type, origin, reason, fromUser,

                        System.currentTimeMillis() /* startTime */);

                        System.currentTimeMillis() /* startWallTimeMs */,

                        SystemClock.elapsedRealtime() /* startTimestampMs */);



                mHistory.putActive(id, newEntry);

                registerTimeout(id, newEntry);
@@ -378,7 +384,7 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
     */

    @GuardedBy("mLock")

    private void complete(long id, @NonNull History.Entry entry) {

        entry.mDuration = entry.mFinishTime - entry.mStartTime;

        entry.mDuration = entry.mFinishTimestampMs - entry.mStartTimestampMs;

        mHandler.removeCallbacksAndMessages(entry /* token */);

        mHistory.complete(id, entry);

        mMetricsRecorder.record(entry);
@@ -554,23 +560,28 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
             */

            private boolean mFinished;



            /** Time in milliseconds when the request was started. */

            @DurationMillisLong

            private long mStartTime;

            /** Wall time in milliseconds when the request was started. */

            @CurrentTimeMillisLong

            private long mStartWallTimeMs;



            /** Time in milliseconds when the request was finished. */

            @DurationMillisLong

            private long mFinishTime;

            /** Time since boot in milliseconds when the request was started. */

            @ElapsedRealtimeLong

            private long mStartTimestampMs;



            /** Time since boot in milliseconds when the request was finished. */

            @ElapsedRealtimeLong

            private long mFinishTimestampMs;



            /** Duration in milliseconds of the request from start to finish. */

            @DurationMillisLong

            private long mDuration;



            /**

             * Clock time in milliseconds when the last {@link #onProgress} call was received. Used

             * in analyzing timed out requests.

             */

            @DurationMillisLong

            private long mLastProgressTime;

            @CurrentTimeMillisLong

            private long mLastProgressWallTimeMs;



            /**

             * Logging tag, of the shape "component:random_hexadecimal".
@@ -617,7 +628,7 @@ public final class ImeTrackerService extends IImeTracker.Stub { 


            Entry() {

                mSequenceNumber = sSequenceNumber.getAndIncrement();

                mLastProgressTime = System.currentTimeMillis();

                mLastProgressWallTimeMs = System.currentTimeMillis();

                mTag = "not set";

                mUid = -1;

                mType = ImeTracker.TYPE_NOT_SET;
@@ -637,20 +648,25 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
             * @param type             the type of the request.

             * @param origin           the origin of the request.

             * @param reason           the reason for starting the request.

             * @param fromUser  whether this request was created directly from user interaction.

             * @param startTime the time in milliseconds when the request was started.

             * @param fromUser         whether this request was created directly from user

             *                         interaction.

             * @param startWallTimeMs  the wall time in milliseconds when the request was started.

             * @param startTimestampMs the time since boot in milliseconds when the request was

             *                         started.

             */

            @GuardedBy("mLock")

            void onStart(@NonNull String tag, int uid, @ImeTracker.Type int type,

                    @ImeTracker.Origin int origin, @SoftInputShowHideReason int reason,

                    boolean fromUser, long startTime) {

                    boolean fromUser, @CurrentTimeMillisLong long startWallTimeMs,

                    @ElapsedRealtimeLong long startTimestampMs) {

                mTag = tag;

                mUid = uid;

                mType = type;

                mOrigin = origin;

                mReason = reason;

                mFromUser = fromUser;

                mStartTime = startTime;

                mStartWallTimeMs = startWallTimeMs;

                mStartTimestampMs = startTimestampMs;

                mStarted = true;

            }
@@ -662,7 +678,7 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
            @GuardedBy("mLock")

            void onProgress(@ImeTracker.Phase int phase) {

                mPhase = phase;

                mLastProgressTime = System.currentTimeMillis();

                mLastProgressWallTimeMs = System.currentTimeMillis();

            }



            /**
@@ -678,7 +694,7 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
                    mPhase = phase;

                }

                mStatus = status;

                mFinishTime = System.currentTimeMillis();

                mFinishTimestampMs = SystemClock.elapsedRealtime();

                mFinished = true;

            }
@@ -699,7 +715,8 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
                pw.println(" (" + mDuration + "ms):");



                pw.print(prefix);

                pw.print("  startTime=" + formatter.format(Instant.ofEpochMilli(mStartTime)));

                pw.print("  startTime=" + formatter.format(Instant.ofEpochMilli(mStartWallTimeMs)));

                pw.print(" (timestamp=" + mStartTimestampMs + ")");

                pw.println(" " + ImeTracker.Debug.originToString(mOrigin));



                pw.print(prefix);
@@ -708,7 +725,7 @@ public final class ImeTrackerService extends IImeTracker.Stub { 


                if (mStatus == ImeTracker.STATUS_TIMEOUT) {

                    pw.print(" lastProgressTime="

                            + formatter.format(Instant.ofEpochMilli(mLastProgressTime)));

                            + formatter.format(Instant.ofEpochMilli(mLastProgressWallTimeMs)));

                }

                pw.println();
@@ -729,8 +746,9 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
                        + ", mPhase: " + ImeTracker.Debug.phaseToString(mPhase)

                        + ", mFromUser: " + mFromUser

                        + ", mRequestWindowName: " + mRequestWindowName

                        + ", mStartTime: " + mStartTime

                        + ", mFinishTime: " + mFinishTime

                        + ", mStartWallTime: " + mStartWallTimeMs

                        + ", mStartTimestamp: " + mStartTimestampMs

                        + ", mFinishTimestamp: " + mFinishTimestampMs

                        + ", mDuration: " + mDuration

                        + ", mStarted: " + mStarted

                        + ", mFinished: " + mFinished

services/tests/InputMethodSystemServerTests/src/com/android/server/inputmethod/ImeTrackerServiceTest.java

+73 −27

File changed.

Preview size limit exceeded, changes collapsed.