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

Commit 2cc68117 authored by Cosmin Băieș's avatar Cosmin Băieș
Browse files

Compare both id and tag in ImeTrackerService 

There are a few instances where statsToken values are stored, to be
re-used and cleared shortly after. In a few of these, if the tokes is
not cleared and re-used later, it could intefere with newer requests, if
the ids match. This is a low chance, as it implies storing a token from
a process that was killed, and a new process is re-using the same pid.

This helps handling this case by comparing both the id and the token's
tag, which contains the process name and a randomly generated hex
number. While comparing on additional randomness is not a perfect
solution, it should decrease the collision chance by enough such that
this scenario is extremely unlikely to occur.

The only downside is this requires also passing in, and thus parcelling,
the tag of the token, for every onProgress call, which occur vastly more
often than onStart or onFinish.

Flag: EXEMPT refactor
Bug: 342111149
Test: atest ImeTrackerServiceTest#testStartOnReusedId
  ImeTrackerServiceTest#testProgressOnReusedId
  ImeTrackerServiceTest#testFinishOnReusedId
Change-Id: I6f8e85461578fd6692982c95c23b1287adeb5183
parent 15b68ff0

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

+2 −2
Original line number Diff line number Diff line
@@ -631,13 +631,13 @@ final class IInputMethodManagerGlobalInvoker { 


    /** @see com.android.server.inputmethod.ImeTrackerService#onProgress */

    @AnyThread

    static void onProgress(long id, @ImeTracker.Phase int phase) {

    static void onProgress(@NonNull ImeTracker.Token statsToken, @ImeTracker.Phase int phase) {

        final IImeTracker service = getImeTrackerService();

        if (service == null) {

            return;

        }

        try {

            service.onProgress(id, phase);

            service.onProgress(statsToken, phase);

        } catch (RemoteException e) {

            throw e.rethrowFromSystemServer();

        }

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

+1 −1
Original line number Diff line number Diff line
@@ -646,7 +646,7 @@ public interface ImeTracker { 
        @Override

        public void onProgress(@Nullable Token token, @Phase int phase) {

            if (token == null) return;

            IInputMethodManagerGlobalInvoker.onProgress(token.mId, phase);

            IInputMethodManagerGlobalInvoker.onProgress(token, phase);



            if (mLogProgress) {

                log("%s: onProgress at %s", token.mTag, Debug.phaseToString(phase));

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

+1 −1
Original line number Diff line number Diff line
@@ -46,7 +46,7 @@ interface IImeTracker { 
     * @param statsToken the token tracking the request.

     * @param phase the new phase the request reached.

     */

    oneway void onProgress(long id, int phase);

    oneway void onProgress(in ImeTracker.Token statsToken, int phase);



    /**

     * Called when the IME request fails.

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

+20 −1
Original line number Diff line number Diff line
@@ -112,6 +112,11 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
            final String tag = statsToken.getTag();

            final var entry = mHistory.getActive(id);

            if (entry != null) {

                if (!entry.mTag.equals(tag)) {

                    // Tags don't match as the ID is being reused after the initial entry completed.

                    Log.i(TAG, tag + ": onStart on previously finished token");

                    return;

                }

                if (entry.mStarted) {

                    Log.i(TAG, tag + ": onStart on previously started and not finished token: "

                            + entry.mTag);
@@ -136,10 +141,16 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
    }



    @Override

    public void onProgress(long id, @ImeTracker.Phase int phase) {

    public void onProgress(@NonNull ImeTracker.Token statsToken, @ImeTracker.Phase int phase) {

        synchronized (mLock) {

            final long id = statsToken.getId();

            final String tag = statsToken.getTag();

            final var entry = mHistory.getActive(id);

            if (entry != null) {

                if (!entry.mTag.equals(tag)) {

                    // Tags don't match as the ID is being reused after the initial entry completed.

                    return;

                }

                if (entry.mFinished) {

                    return;

                }
@@ -151,6 +162,7 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
                }



                final var newEntry = new History.Entry();

                newEntry.mTag = tag;

                newEntry.onProgress(phase);



                mHistory.putActive(id, newEntry);
@@ -174,6 +186,13 @@ public final class ImeTrackerService extends IImeTracker.Stub { 
        final String tag = statsToken.getTag();

        final var entry = mHistory.getActive(id);

        if (entry != null) {

            if (!entry.mTag.equals(tag)) {

                //  Tags don't match as the ID is being reused after the initial entry completed.

                Log.i(TAG, tag + ": onFinished on previously finished token at "

                        + ImeTracker.Debug.phaseToString(phase) + " with "

                        + ImeTracker.Debug.statusToString(status));

                return;

            }

            if (entry.mFinished) {

                Log.i(TAG, tag + ": onFinished on previously finished but active token at "

                        + ImeTracker.Debug.phaseToString(phase)

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

+173 −13
Original line number Diff line number Diff line
@@ -80,7 +80,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onProgress(id, ImeTracker.PHASE_CLIENT_VIEW_SERVED);

        mService.onProgress(token, ImeTracker.PHASE_CLIENT_VIEW_SERVED);



        mService.onShown(token);

        synchronized (mService.mLock) {
@@ -112,7 +112,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onProgress(id, ImeTracker.PHASE_CLIENT_ALREADY_HIDDEN);

        mService.onProgress(token, ImeTracker.PHASE_CLIENT_ALREADY_HIDDEN);



        mService.onHidden(token);

        synchronized (mService.mLock) {
@@ -144,7 +144,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onProgress(id, ImeTracker.PHASE_CLIENT_CONTROL_ANIMATION);

        mService.onProgress(token, ImeTracker.PHASE_CLIENT_CONTROL_ANIMATION);



        mService.onCancelled(token, ImeTracker.PHASE_CLIENT_ANIMATION_CANCEL);

        synchronized (mService.mLock) {
@@ -176,7 +176,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onProgress(id, ImeTracker.PHASE_IME_SHOW_WINDOW);

        mService.onProgress(token, ImeTracker.PHASE_IME_SHOW_WINDOW);



        mService.onFailed(token, ImeTracker.PHASE_CLIENT_SHOW_INSETS);

        synchronized (mService.mLock) {
@@ -208,7 +208,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onProgress(id, ImeTracker.PHASE_CLIENT_ANIMATION_RUNNING);

        mService.onProgress(token, ImeTracker.PHASE_CLIENT_ANIMATION_RUNNING);



        mService.onDispatched(token);

        synchronized (mService.mLock) {
@@ -247,7 +247,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("One active entry").that(mHistory.activeEntries()).hasSize(1);

        }



        mService.onProgress(id, ImeTracker.PHASE_SERVER_SYSTEM_READY);

        mService.onProgress(token, ImeTracker.PHASE_SERVER_SYSTEM_READY);



        mService.onShown(token);

        synchronized (mService.mLock) {
@@ -309,6 +309,53 @@ public class ImeTrackerServiceTest { 
                reason, ImeTracker.PHASE_CLIENT_VIEW_SERVED, fromUser);

    }



    /**

     * Check that a start from a completed entry won't affect a new entry that is

     * re-using the id.

     */

    @Test

    public void testStartOnReusedId() {

        final int id = 0;

        final var tag = "A";

        final var token = new ImeTracker.Token(id, tag);

        final int uid = 10;

        final int type = ImeTracker.TYPE_SHOW;

        final int origin = ImeTracker.ORIGIN_CLIENT;

        final int reason = SoftInputShowHideReason.SHOW_SOFT_INPUT;

        final boolean fromUser = false;



        final var secondTag = "B";

        final var secondToken = new ImeTracker.Token(id, secondTag);

        final int secondType = ImeTracker.TYPE_HIDE;

        mService.onCancelled(secondToken, ImeTracker.PHASE_SERVER_SHOULD_HIDE);

        synchronized (mService.mLock) {

            assertWithMessage("Second created entry").that(mHistory.getActive(id)).isNotNull();

        }



        // Emulate start on token of completed entry. Completing an entry with the id will allow

        // re-using the id for token creation only in onStart, but that scenario is already

        // checked in testStartTwice. This emulated scenario can happen if the completed entry is

        // old, and the history is flushed due to many new entries.

        mService.onStart(token, uid, type, origin, reason, fromUser, System.currentTimeMillis());

        synchronized (mService.mLock) {

            assertWithMessage("One active entry").that(mHistory.activeEntries()).hasSize(1);

        }



        mService.onStart(secondToken, uid, secondType, origin, reason, fromUser,

                System.currentTimeMillis());

        synchronized (mService.mLock) {

            assertWithMessage("No active entries remaining").that(mHistory.activeEntries())

                    .isEmpty();

        }



        advanceTime(TIMEOUT_MS);



        assertWithMessage("One recorded").that(mRecordedEntries).hasSize(1);

        verifyEntry(mRecordedEntries.getFirst(), secondTag, uid, secondType,

                ImeTracker.STATUS_CANCEL, origin, reason, ImeTracker.PHASE_SERVER_SHOULD_HIDE,

                fromUser);

    }



    /**

     * Check that an entry that is first progressed, then started and then finished will be

     * completed normally, and contain the given data.
@@ -324,7 +371,7 @@ public class ImeTrackerServiceTest { 
        final int reason = SoftInputShowHideReason.SHOW_SOFT_INPUT;

        final boolean fromUser = false;



        mService.onProgress(id, ImeTracker.PHASE_SERVER_HAS_IME);

        mService.onProgress(token, ImeTracker.PHASE_SERVER_HAS_IME);

        synchronized (mService.mLock) {

            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }
@@ -364,7 +411,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onProgress(id, ImeTracker.PHASE_SERVER_CLIENT_KNOWN);

        mService.onProgress(token, ImeTracker.PHASE_SERVER_CLIENT_KNOWN);



        mService.onStart(token, uid, type, origin, reason, fromUser, System.currentTimeMillis());

        synchronized (mService.mLock) {
@@ -399,7 +446,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onProgress(id, ImeTracker.PHASE_CLIENT_VIEW_SERVED);

        mService.onProgress(token, ImeTracker.PHASE_CLIENT_VIEW_SERVED);



        mService.onShown(token);

        synchronized (mService.mLock) {
@@ -407,7 +454,7 @@ public class ImeTrackerServiceTest { 
                    .isEmpty();

        }



        mService.onProgress(id, ImeTracker.PHASE_SERVER_CLIENT_KNOWN);

        mService.onProgress(token, ImeTracker.PHASE_SERVER_CLIENT_KNOWN);

        synchronized (mService.mLock) {

            assertWithMessage("No entry created for progress after complete")

                    .that(mHistory.getActive(id)).isNull();
@@ -420,6 +467,62 @@ public class ImeTrackerServiceTest { 
                reason, ImeTracker.PHASE_CLIENT_VIEW_SERVED, fromUser);

    }



    /**

     * Check that a progress from a completed entry won't affect a new entry that is

     * re-using the id.

     */

    @Test

    public void testProgressOnReusedId() {

        final int id = 0;

        final var tag = "A";

        final var token = new ImeTracker.Token(id, tag);

        final int uid = 10;

        final int type = ImeTracker.TYPE_SHOW;

        final int origin = ImeTracker.ORIGIN_CLIENT;

        final int reason = SoftInputShowHideReason.SHOW_SOFT_INPUT;

        final boolean fromUser = false;



        mService.onStart(token, uid, type, origin, reason, fromUser, System.currentTimeMillis());

        synchronized (mService.mLock) {

            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onShown(token);

        synchronized (mService.mLock) {

            assertWithMessage("No active entries remaining").that(mHistory.activeEntries())

                    .isEmpty();

        }



        final var secondTag = "B";

        final var secondToken = new ImeTracker.Token(id, secondTag);

        final int secondType = ImeTracker.TYPE_HIDE;

        mService.onStart(secondToken, uid, secondType, origin, reason, fromUser,

                System.currentTimeMillis());

        synchronized (mService.mLock) {

            assertWithMessage("Second created entry").that(mHistory.getActive(id)).isNotNull();

        }



        // Progress on token of completed entry.

        mService.onProgress(token, ImeTracker.PHASE_CLIENT_VIEW_SERVED);

        synchronized (mService.mLock) {

            assertWithMessage("One active entry").that(mHistory.activeEntries()).hasSize(1);

        }



        mService.onCancelled(secondToken, ImeTracker.PHASE_SERVER_SHOULD_HIDE);

        synchronized (mService.mLock) {

            assertWithMessage("No active entries remaining").that(mHistory.activeEntries())

                    .isEmpty();

        }



        advanceTime(TIMEOUT_MS);



        assertWithMessage("Two entries recorded").that(mRecordedEntries).hasSize(2);

        verifyEntry(mRecordedEntries.get(0), tag, uid, type, ImeTracker.STATUS_SUCCESS, origin,

                reason, ImeTracker.PHASE_NOT_SET, fromUser);

        verifyEntry(mRecordedEntries.get(1), secondTag, uid, secondType, ImeTracker.STATUS_CANCEL,

                origin, reason, ImeTracker.PHASE_SERVER_SHOULD_HIDE, fromUser);

    }



    /**

     * Check that an entry that is first finished, then started and will be completed normally,

     * and contain the given data.
@@ -528,6 +631,62 @@ public class ImeTrackerServiceTest { 
                reason, ImeTracker.PHASE_NOT_SET, fromUser);

    }



    /**

     * Check that a finish from a completed entry won't affect a new entry that is

     * re-using the id.

     */

    @Test

    public void testFinishOnReusedId() {

        final int id = 0;

        final var tag = "A";

        final var token = new ImeTracker.Token(id, tag);

        final int uid = 10;

        final int type = ImeTracker.TYPE_SHOW;

        final int origin = ImeTracker.ORIGIN_CLIENT;

        final int reason = SoftInputShowHideReason.SHOW_SOFT_INPUT;

        final boolean fromUser = false;



        mService.onStart(token, uid, type, origin, reason, fromUser, System.currentTimeMillis());

        synchronized (mService.mLock) {

            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onShown(token);

        synchronized (mService.mLock) {

            assertWithMessage("No active entries remaining").that(mHistory.activeEntries())

                    .isEmpty();

        }



        final var secondTag = "B";

        final var secondToken = new ImeTracker.Token(id, secondTag);

        final int secondType = ImeTracker.TYPE_HIDE;

        mService.onStart(secondToken, uid, secondType, origin, reason, fromUser,

                System.currentTimeMillis());

        synchronized (mService.mLock) {

            assertWithMessage("Second created entry").that(mHistory.getActive(id)).isNotNull();

        }



        // Finish on token of completed entry.

        mService.onFailed(token, ImeTracker.PHASE_CLIENT_VIEW_SERVED);

        synchronized (mService.mLock) {

            assertWithMessage("One active entry").that(mHistory.activeEntries()).hasSize(1);

        }



        mService.onCancelled(secondToken, ImeTracker.PHASE_SERVER_SHOULD_HIDE);

        synchronized (mService.mLock) {

            assertWithMessage("No active entries remaining").that(

                    mHistory.activeEntries()).isEmpty();

        }



        advanceTime(TIMEOUT_MS);



        assertWithMessage("Two entries recorded").that(mRecordedEntries).hasSize(2);

        verifyEntry(mRecordedEntries.get(0), tag, uid, type, ImeTracker.STATUS_SUCCESS, origin,

                reason, ImeTracker.PHASE_NOT_SET, fromUser);

        verifyEntry(mRecordedEntries.get(1), secondTag, uid, secondType, ImeTracker.STATUS_CANCEL,

                origin, reason, ImeTracker.PHASE_SERVER_SHOULD_HIDE, fromUser);

    }



    /** Check that a started entry that is not completed will time out. */

    @Test

    public void testTimeoutFromStart() {
@@ -545,7 +704,7 @@ public class ImeTrackerServiceTest { 
            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }



        mService.onProgress(id, ImeTracker.PHASE_SERVER_WAIT_IME);

        mService.onProgress(token, ImeTracker.PHASE_SERVER_WAIT_IME);



        advanceTime(TIMEOUT_MS);
@@ -562,14 +721,15 @@ public class ImeTrackerServiceTest { 
    @Test

    public void testTimeoutFromProgress() {

        final int id = 0;

        final var tag = "not set";

        final var tag = "A";

        final var token = new ImeTracker.Token(id, tag);

        final int uid = -1;

        final int type = ImeTracker.TYPE_NOT_SET;

        final int origin = ImeTracker.ORIGIN_NOT_SET;

        final int reason = SoftInputShowHideReason.NOT_SET;

        final boolean fromUser = false;



        mService.onProgress(id, ImeTracker.PHASE_SERVER_HAS_IME);

        mService.onProgress(token, ImeTracker.PHASE_SERVER_HAS_IME);

        synchronized (mService.mLock) {

            assertWithMessage("Created entry").that(mHistory.getActive(id)).isNotNull();

        }