• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2022 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 package com.android.server.inputmethod;
18 
19 import android.Manifest;
20 import android.annotation.EnforcePermission;
21 import android.annotation.NonNull;
22 import android.annotation.Nullable;
23 import android.os.Binder;
24 import android.os.Handler;
25 import android.os.IBinder;
26 import android.util.Log;
27 import android.view.inputmethod.ImeTracker;
28 
29 import com.android.internal.annotations.GuardedBy;
30 import com.android.internal.infra.AndroidFuture;
31 import com.android.internal.inputmethod.IImeTracker;
32 import com.android.internal.inputmethod.InputMethodDebug;
33 import com.android.internal.inputmethod.SoftInputShowHideReason;
34 import com.android.internal.util.FrameworkStatsLog;
35 
36 import java.io.PrintWriter;
37 import java.time.Instant;
38 import java.time.ZoneId;
39 import java.time.format.DateTimeFormatter;
40 import java.util.ArrayDeque;
41 import java.util.Locale;
42 import java.util.WeakHashMap;
43 import java.util.concurrent.atomic.AtomicInteger;
44 
45 /**
46  * Service for managing and logging {@link ImeTracker.Token} instances.
47  *
48  * @implNote Suppresses {@link GuardedBy} warnings, as linter reports that {@link #mHistory}
49  * interactions are guarded by {@code this} instead of {@code ImeTrackerService.this}, which should
50  * be identical.
51  *
52  * @hide
53  */
54 @SuppressWarnings("GuardedBy")
55 public final class ImeTrackerService extends IImeTracker.Stub {
56 
57     private static final String TAG = ImeTracker.TAG;
58 
59     /** The threshold in milliseconds after which a history entry is considered timed out. */
60     private static final long TIMEOUT_MS = 10_000;
61 
62     /** Handler for registering timeouts for live entries. */
63     @GuardedBy("mLock")
64     private final Handler mHandler;
65 
66     /** Singleton instance of the History. */
67     @GuardedBy("mLock")
68     private final History mHistory = new History();
69 
70     private final Object mLock = new Object();
71 
ImeTrackerService(@onNull Handler handler)72     ImeTrackerService(@NonNull Handler handler) {
73         mHandler = handler;
74     }
75 
76     @NonNull
77     @Override
onStart(@onNull String tag, int uid, @ImeTracker.Type int type, @ImeTracker.Origin int origin, @SoftInputShowHideReason int reason, boolean fromUser)78     public ImeTracker.Token onStart(@NonNull String tag, int uid, @ImeTracker.Type int type,
79             @ImeTracker.Origin int origin, @SoftInputShowHideReason int reason, boolean fromUser) {
80         final var binder = new Binder();
81         final var token = new ImeTracker.Token(binder, tag);
82         final var entry = new History.Entry(tag, uid, type, ImeTracker.STATUS_RUN, origin, reason,
83                 fromUser);
84         synchronized (mLock) {
85             mHistory.addEntry(binder, entry);
86 
87             // Register a delayed task to handle the case where the new entry times out.
88             mHandler.postDelayed(() -> {
89                 synchronized (mLock) {
90                     mHistory.setFinished(token, ImeTracker.STATUS_TIMEOUT,
91                             ImeTracker.PHASE_NOT_SET);
92                 }
93             }, TIMEOUT_MS);
94         }
95         return token;
96     }
97 
98     @Override
onProgress(@onNull IBinder binder, @ImeTracker.Phase int phase)99     public void onProgress(@NonNull IBinder binder, @ImeTracker.Phase int phase) {
100         synchronized (mLock) {
101             final var entry = mHistory.getEntry(binder);
102             if (entry == null) return;
103 
104             entry.mPhase = phase;
105         }
106     }
107 
108     @Override
onFailed(@onNull ImeTracker.Token statsToken, @ImeTracker.Phase int phase)109     public void onFailed(@NonNull ImeTracker.Token statsToken, @ImeTracker.Phase int phase) {
110         synchronized (mLock) {
111             mHistory.setFinished(statsToken, ImeTracker.STATUS_FAIL, phase);
112         }
113     }
114 
115     @Override
onCancelled(@onNull ImeTracker.Token statsToken, @ImeTracker.Phase int phase)116     public void onCancelled(@NonNull ImeTracker.Token statsToken, @ImeTracker.Phase int phase) {
117         synchronized (mLock) {
118             mHistory.setFinished(statsToken, ImeTracker.STATUS_CANCEL, phase);
119         }
120     }
121 
122     @Override
onShown(@onNull ImeTracker.Token statsToken)123     public void onShown(@NonNull ImeTracker.Token statsToken) {
124         synchronized (mLock) {
125             mHistory.setFinished(statsToken, ImeTracker.STATUS_SUCCESS, ImeTracker.PHASE_NOT_SET);
126         }
127     }
128 
129     @Override
onHidden(@onNull ImeTracker.Token statsToken)130     public void onHidden(@NonNull ImeTracker.Token statsToken) {
131         synchronized (mLock) {
132             mHistory.setFinished(statsToken, ImeTracker.STATUS_SUCCESS, ImeTracker.PHASE_NOT_SET);
133         }
134     }
135 
136     @Override
onDispatched(@onNull ImeTracker.Token statsToken)137     public void onDispatched(@NonNull ImeTracker.Token statsToken) {
138         synchronized (mLock) {
139             mHistory.setFinished(statsToken, ImeTracker.STATUS_SUCCESS, ImeTracker.PHASE_NOT_SET);
140         }
141     }
142 
143     /**
144      * Updates the IME request tracking token with new information available in IMMS.
145      *
146      * @param statsToken the token tracking the current IME request.
147      * @param requestWindowName the name of the window that created the IME request.
148      */
onImmsUpdate(@onNull ImeTracker.Token statsToken, @NonNull String requestWindowName)149     public void onImmsUpdate(@NonNull ImeTracker.Token statsToken,
150             @NonNull String requestWindowName) {
151         synchronized (mLock) {
152             final var entry = mHistory.getEntry(statsToken.getBinder());
153             if (entry == null) return;
154 
155             entry.mRequestWindowName = requestWindowName;
156         }
157     }
158 
159     /** Dumps the contents of the history. */
dump(@onNull PrintWriter pw, @NonNull String prefix)160     public void dump(@NonNull PrintWriter pw, @NonNull String prefix) {
161         synchronized (mLock) {
162             mHistory.dump(pw, prefix);
163         }
164     }
165 
166     @EnforcePermission(Manifest.permission.TEST_INPUT_METHOD)
167     @Override
hasPendingImeVisibilityRequests()168     public boolean hasPendingImeVisibilityRequests() {
169         super.hasPendingImeVisibilityRequests_enforcePermission();
170         synchronized (mLock) {
171             return !mHistory.mLiveEntries.isEmpty();
172         }
173     }
174 
175     @EnforcePermission(Manifest.permission.TEST_INPUT_METHOD)
176     @Override
finishTrackingPendingImeVisibilityRequests( @onNull AndroidFuture completionSignal )177     public void finishTrackingPendingImeVisibilityRequests(
178             @NonNull AndroidFuture completionSignal /* T=Void */) {
179         super.finishTrackingPendingImeVisibilityRequests_enforcePermission();
180         @SuppressWarnings("unchecked")
181         final AndroidFuture<Void> typedCompletionSignal = completionSignal;
182         try {
183             synchronized (mLock) {
184                 mHistory.mLiveEntries.clear();
185             }
186             typedCompletionSignal.complete(null);
187         } catch (Throwable e) {
188             typedCompletionSignal.completeExceptionally(e);
189         }
190     }
191 
192     /**
193      * A circular buffer storing the most recent few {@link ImeTracker.Token} entries information.
194      */
195     private static final class History {
196 
197         /** The circular buffer's capacity. */
198         private static final int CAPACITY = 100;
199 
200         /** Backing store for the circular buffer. */
201         @GuardedBy("ImeTrackerService.this")
202         private final ArrayDeque<Entry> mEntries = new ArrayDeque<>(CAPACITY);
203 
204         /** Backing store for the live entries (i.e. entries that are not finished yet). */
205         @GuardedBy("ImeTrackerService.this")
206         private final WeakHashMap<IBinder, Entry> mLiveEntries = new WeakHashMap<>();
207 
208         /** Latest entry sequence number. */
209         private static final AtomicInteger sSequenceNumber = new AtomicInteger(0);
210 
211         /** Adds a live entry corresponding to the given IME tracking token's binder. */
212         @GuardedBy("ImeTrackerService.this")
addEntry(@onNull IBinder binder, @NonNull Entry entry)213         private void addEntry(@NonNull IBinder binder, @NonNull Entry entry) {
214             mLiveEntries.put(binder, entry);
215         }
216 
217         /** Gets the entry corresponding to the given IME tracking token's binder, if it exists. */
218         @Nullable
219         @GuardedBy("ImeTrackerService.this")
getEntry(@onNull IBinder binder)220         private Entry getEntry(@NonNull IBinder binder) {
221             return mLiveEntries.get(binder);
222         }
223 
224         /**
225          * Sets the live entry corresponding to the tracking token, if it exists, as finished,
226          * and uploads the data for metrics.
227          *
228          * @param statsToken the token tracking the current IME request.
229          * @param status the finish status of the IME request.
230          * @param phase the phase the IME request finished at, if it exists
231          *              (or {@link ImeTracker#PHASE_NOT_SET} otherwise).
232          */
233         @GuardedBy("ImeTrackerService.this")
setFinished(@onNull ImeTracker.Token statsToken, @ImeTracker.Status int status, @ImeTracker.Phase int phase)234         private void setFinished(@NonNull ImeTracker.Token statsToken,
235                 @ImeTracker.Status int status, @ImeTracker.Phase int phase) {
236             final var entry = mLiveEntries.remove(statsToken.getBinder());
237             if (entry == null) {
238                 // This will be unconditionally called through the postDelayed above to handle
239                 // potential timeouts, and is thus intentionally dropped to avoid having to manually
240                 // save and remove the registered callback. Only timeout calls are expected.
241                 if (status != ImeTracker.STATUS_TIMEOUT) {
242                     Log.i(TAG, statsToken.getTag()
243                             + ": setFinished on previously finished token at "
244                             + ImeTracker.Debug.phaseToString(phase) + " with "
245                             + ImeTracker.Debug.statusToString(status));
246                 }
247                 return;
248             }
249 
250             entry.mDuration = System.currentTimeMillis() - entry.mStartTime;
251             entry.mStatus = status;
252 
253             if (phase != ImeTracker.PHASE_NOT_SET) {
254                 entry.mPhase = phase;
255             }
256 
257             if (status == ImeTracker.STATUS_TIMEOUT) {
258                 // All events other than timeouts are already logged in the client-side ImeTracker.
259                 Log.i(TAG, statsToken.getTag() + ": setFinished at "
260                         + ImeTracker.Debug.phaseToString(entry.mPhase) + " with "
261                         + ImeTracker.Debug.statusToString(status));
262             }
263 
264             // Remove excess entries overflowing capacity (plus one for the new entry).
265             while (mEntries.size() >= CAPACITY) {
266                 mEntries.remove();
267             }
268 
269             mEntries.offer(entry);
270 
271             // Log newly finished entry.
272             FrameworkStatsLog.write(FrameworkStatsLog.IME_REQUEST_FINISHED, entry.mUid,
273                     entry.mDuration, entry.mType, entry.mStatus, entry.mReason,
274                     entry.mOrigin, entry.mPhase, entry.mFromUser);
275         }
276 
277         /** Dumps the contents of the circular buffer. */
278         @GuardedBy("ImeTrackerService.this")
dump(@onNull PrintWriter pw, @NonNull String prefix)279         private void dump(@NonNull PrintWriter pw, @NonNull String prefix) {
280             final var formatter = DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss.SSS", Locale.US)
281                     .withZone(ZoneId.systemDefault());
282 
283             pw.print(prefix);
284             pw.println("mLiveEntries: " + mLiveEntries.size() + " elements");
285 
286             for (final var entry: mLiveEntries.values()) {
287                 dumpEntry(entry, pw, prefix + "  ", formatter);
288             }
289             pw.print(prefix);
290             pw.println("mEntries: " + mEntries.size() + " elements");
291 
292             for (final var entry: mEntries) {
293                 dumpEntry(entry, pw, prefix + "  ", formatter);
294             }
295         }
296 
297         @GuardedBy("ImeTrackerService.this")
dumpEntry(@onNull Entry entry, @NonNull PrintWriter pw, @NonNull String prefix, @NonNull DateTimeFormatter formatter)298         private void dumpEntry(@NonNull Entry entry, @NonNull PrintWriter pw,
299                 @NonNull String prefix, @NonNull DateTimeFormatter formatter) {
300             pw.print(prefix);
301             pw.print("#" + entry.mSequenceNumber);
302             pw.print(" " + ImeTracker.Debug.typeToString(entry.mType));
303             pw.print(" - " + ImeTracker.Debug.statusToString(entry.mStatus));
304             pw.print(" - " + entry.mTag);
305             pw.println(" (" + entry.mDuration + "ms):");
306 
307             pw.print(prefix);
308             pw.print("  startTime=" + formatter.format(Instant.ofEpochMilli(entry.mStartTime)));
309             pw.println(" " + ImeTracker.Debug.originToString(entry.mOrigin));
310 
311             pw.print(prefix);
312             pw.print("  reason=" + InputMethodDebug.softInputDisplayReasonToString(entry.mReason));
313             pw.println(" " + ImeTracker.Debug.phaseToString(entry.mPhase));
314 
315             pw.print(prefix);
316             pw.println("  requestWindowName=" + entry.mRequestWindowName);
317         }
318 
319         /** A history entry. */
320         private static final class Entry {
321 
322             /** The entry's sequence number in the history. */
323             private final int mSequenceNumber = sSequenceNumber.getAndIncrement();
324 
325             /** Logging tag, of the shape "component:random_hexadecimal". */
326             @NonNull
327             private final String mTag;
328 
329             /** Uid of the client that requested the IME. */
330             private final int mUid;
331 
332             /** Clock time in milliseconds when the IME request was created. */
333             private final long mStartTime = System.currentTimeMillis();
334 
335             /** Duration in milliseconds of the IME request from start to end. */
336             private long mDuration = 0;
337 
338             /** Type of the IME request. */
339             @ImeTracker.Type
340             private final int mType;
341 
342             /** Status of the IME request. */
343             @ImeTracker.Status
344             private int mStatus;
345 
346             /** Origin of the IME request. */
347             @ImeTracker.Origin
348             private final int mOrigin;
349 
350             /** Reason for creating the IME request. */
351             @SoftInputShowHideReason
352             private final int mReason;
353 
354             /** Latest phase of the IME request. */
355             @ImeTracker.Phase
356             private int mPhase = ImeTracker.PHASE_NOT_SET;
357 
358             /** Whether this request was created directly from a user interaction. */
359             private final boolean mFromUser;
360 
361             /**
362              * Name of the window that created the IME request.
363              *
364              * Note: This is later set through {@link #onImmsUpdate}.
365              */
366             @NonNull
367             private String mRequestWindowName = "not set";
368 
Entry(@onNull String tag, int uid, @ImeTracker.Type int type, @ImeTracker.Status int status, @ImeTracker.Origin int origin, @SoftInputShowHideReason int reason, boolean fromUser)369             private Entry(@NonNull String tag, int uid, @ImeTracker.Type int type,
370                     @ImeTracker.Status int status, @ImeTracker.Origin int origin,
371                     @SoftInputShowHideReason int reason, boolean fromUser) {
372                 mTag = tag;
373                 mUid = uid;
374                 mType = type;
375                 mStatus = status;
376                 mOrigin = origin;
377                 mReason = reason;
378                 mFromUser = fromUser;
379             }
380         }
381     }
382 }
383