No warning/info log for expected/normal situations

This CL hides warning and info log messages from
InputMethodManagerService (IMMS) and InputMethodService (IMS) behind
DEBUG flag like other logs unless the state is certainly unusual.

Of course the definition of "unusual" is still an open question, but
basically that we should not see any suspicious message from IMMS/IMS
just by turning on a new phone, launching some applications, typing
something, and turning off the device. IMMS and IMS should expect all
events that can (easily) occur in that scenario, and no log is
necessary for such things.

Note that warnings suppressed with TODO comments will be tracked
under Bug 34851776 (and Bug 34886274).

Test: adb logcat -s InputMethodManagerService:* InputMethodService:*
      to monitor log in the following scenario:
       1. Boot the device.
       2. Complete the setup wizard.
       3. Launch Dialer and type something on it.
       4. Launch Contacts app and type something on it.
       5. Try some special modes:
           - Turn on/off display
           - Recents screen
           - Split-window mode
           - Guest user
           - Multi user
           - Direct-boot (setup a device password and reboot)
      except for logs about actual IPC calls from a background user.
Bug: 34838583
Bug: 34851776
Bug: 34886274
Change-Id: I3fcdeb919bb2f2940da9ff45e17ac00baa1253f4

diff --git a/core/java/android/inputmethodservice/InputMethodService.java b/core/java/android/inputmethodservice/InputMethodService.java
index beed6e9..5996fe2 100644 (file)
--- a/core/java/android/inputmethodservice/InputMethodService.java
+++ b/core/java/android/inputmethodservice/InputMethodService.java
@@ -1084,8 +1084,10 @@ public class InputMethodService extends AbstractInputMethodService {
         final int currentHeight = mWindow.getWindow().getAttributes().height;
         final int newHeight = isFullscreen ? MATCH_PARENT : WRAP_CONTENT;
         if (mIsInputViewShown && currentHeight != newHeight) {
-            Log.w(TAG, "Window size has been changed. This may cause jankiness of resizing window: "
-                    + currentHeight + " -> " + newHeight);
+            if (DEBUG) {
+                Log.w(TAG,"Window size has been changed. This may cause jankiness of resizing "
+                        + "window: " + currentHeight + " -> " + newHeight);
+            }
         }
         mWindow.getWindow().setLayout(MATCH_PARENT, newHeight);
     }

diff --git a/services/core/java/com/android/server/InputMethodManagerService.java b/services/core/java/com/android/server/InputMethodManagerService.java
index 8020f0e..3e711ec 100644 (file)
--- a/services/core/java/com/android/server/InputMethodManagerService.java
+++ b/services/core/java/com/android/server/InputMethodManagerService.java
@@ -932,7 +932,9 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
             return;
         }
         final InputMethodInfo defIm = suitableImes.get(0);
-        Slog.i(TAG, "Default found, using " + defIm.getId());
+        if (DEBUG) {
+            Slog.i(TAG, "Default found, using " + defIm.getId());
+        }
         setSelectedInputMethodAndSubtypeLocked(defIm, NOT_A_SUBTYPE_ID, false);
     }
 
@@ -1123,6 +1125,7 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
             }
             return true;
         }
+        // TODO(b/34886274): The semantics of this verification is actually not well-defined.
         Slog.w(TAG, "--- IPC called from background users. Ignore. callers="
                 + Debug.getCallers(10));
         return false;
@@ -1134,8 +1137,18 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
      * @param token The window token given to the input method when it was started.
      * @return true if and only if non-null valid token is specified.
      */
-    private boolean calledWithValidToken(IBinder token) {
-        if (token == null || mCurToken != token) {
+    private boolean calledWithValidToken(@Nullable IBinder token) {
+        if (token == null && Binder.getCallingPid() == Process.myPid()) {
+            if (DEBUG) {
+                // TODO(b/34851776): Basically it's the caller's fault if we reach here.
+                Slog.d(TAG, "Bug 34851776 is detected callers=" + Debug.getCallers(10));
+            }
+            return false;
+        }
+        if (token == null || token != mCurToken) {
+            // TODO(b/34886274): The semantics of this verification is actually not well-defined.
+            Slog.e(TAG, "Ignoring " + Debug.getCaller() + " due to an invalid token."
+                    + " uid:" + Binder.getCallingUid() + " token:" + token);
             return false;
         }
         return true;
@@ -1338,8 +1351,10 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
                 // because if the focus changes some time before or after, the
                 // next client receiving focus that has any interest in input will
                 // be calling through here after that change happens.
-                Slog.w(TAG, "Starting input on non-focused client " + cs.client
-                        + " (uid=" + cs.uid + " pid=" + cs.pid + ")");
+                if (DEBUG) {
+                    Slog.w(TAG, "Starting input on non-focused client " + cs.client
+                            + " (uid=" + cs.uid + " pid=" + cs.pid + ")");
+                }
                 return null;
             }
         } catch (RemoteException e) {
@@ -1457,7 +1472,7 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
             mCurId = info.getId();
             mCurToken = new Binder();
             try {
-                if (true || DEBUG) Slog.v(TAG, "Adding window token: " + mCurToken);
+                if (DEBUG) Slog.v(TAG, "Adding window token: " + mCurToken);
                 mIWindowManager.addWindowToken(mCurToken, TYPE_INPUT_METHOD, DEFAULT_DISPLAY);
             } catch (RemoteException e) {
             }
@@ -1662,9 +1677,6 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
     public void updateStatusIcon(IBinder token, String packageName, int iconId) {
         synchronized (mMethodMap) {
             if (!calledWithValidToken(token)) {
-                final int uid = Binder.getCallingUid();
-                Slog.e(TAG, "Ignoring updateStatusIcon due to an invalid token. uid:" + uid
-                        + " token:" + token);
                 return;
             }
             final long ident = Binder.clearCallingIdentity();
@@ -1767,9 +1779,6 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
     @Override
     public void setImeWindowStatus(IBinder token, int vis, int backDisposition) {
         if (!calledWithValidToken(token)) {
-            final int uid = Binder.getCallingUid();
-            Slog.e(TAG, "Ignoring setImeWindowStatus due to an invalid token. uid:" + uid
-                    + " token:" + token);
             return;
         }
 
@@ -1789,9 +1798,6 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
     // Caution! This method is called in this class. Handle multi-user carefully
     private void updateSystemUiLocked(IBinder token, int vis, int backDisposition) {
         if (!calledWithValidToken(token)) {
-            final int uid = Binder.getCallingUid();
-            Slog.e(TAG, "Ignoring updateSystemUiLocked due to an invalid token. uid:" + uid
-                    + " token:" + token);
             return;
         }
 
@@ -2259,8 +2265,10 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
                         // because if the focus changes some time before or after, the
                         // next client receiving focus that has any interest in input will
                         // be calling through here after that change happens.
-                        Slog.w(TAG, "Focus gain on non-focused client " + cs.client
-                                + " (uid=" + cs.uid + " pid=" + cs.pid + ")");
+                        if (DEBUG) {
+                            Slog.w(TAG, "Focus gain on non-focused client " + cs.client
+                                    + " (uid=" + cs.uid + " pid=" + cs.pid + ")");
+                        }
                         return null;
                     }
                 } catch (RemoteException e) {
@@ -2275,8 +2283,10 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
                 }
 
                 if (mCurFocusedWindow == windowToken) {
-                    Slog.w(TAG, "Window already focused, ignoring focus gain of: " + client
-                            + " attribute=" + attribute + ", token = " + windowToken);
+                    if (DEBUG) {
+                        Slog.w(TAG, "Window already focused, ignoring focus gain of: " + client
+                                + " attribute=" + attribute + ", token = " + windowToken);
+                    }
                     if (attribute != null) {
                         return startInputUncheckedLocked(cs, inputContext, missingMethods,
                                 attribute, controlFlags);
@@ -2519,9 +2529,6 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
         }
         synchronized (mMethodMap) {
             if (!calledWithValidToken(token)) {
-                final int uid = Binder.getCallingUid();
-                Slog.e(TAG, "Ignoring switchToNextInputMethod due to an invalid token. uid:" + uid
-                        + " token:" + token);
                 return false;
             }
             final ImeSubtypeListItem nextSubtype = mSwitchingController.getNextInputMethodLocked(
@@ -2543,9 +2550,6 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
         }
         synchronized (mMethodMap) {
             if (!calledWithValidToken(token)) {
-                final int uid = Binder.getCallingUid();
-                Slog.e(TAG, "Ignoring shouldOfferSwitchingToNextInputMethod due to an invalid "
-                        + "token. uid:" + uid + " token:" + token);
                 return false;
             }
             final ImeSubtypeListItem nextSubtype = mSwitchingController.getNextInputMethodLocked(
@@ -2636,9 +2640,6 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
         }
         synchronized (mMethodMap) {
             if (!calledWithValidToken(token)) {
-                final int uid = Binder.getCallingUid();
-                Slog.e(TAG, "Ignoring clearLastInputMethodWindowForTransition due to an "
-                        + "invalid token. uid:" + uid + " token:" + token);
                 return;
             }
         }
@@ -2702,9 +2703,6 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
         }
         synchronized (mMethodMap) {
             if (!calledWithValidToken(token)) {
-                final int uid = Binder.getCallingUid();
-                Slog.e(TAG, "Ignoring hideInputMethod due to an invalid token. uid:"
-                        + uid + " token:" + token);
                 return;
             }
             long ident = Binder.clearCallingIdentity();
@@ -2723,9 +2721,6 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
         }
         synchronized (mMethodMap) {
             if (!calledWithValidToken(token)) {
-                final int uid = Binder.getCallingUid();
-                Slog.e(TAG, "Ignoring showMySoftInput due to an invalid token. uid:"
-                        + uid + " token:" + token);
                 return;
             }
             long ident = Binder.clearCallingIdentity();
@@ -3076,7 +3071,9 @@ public class InputMethodManagerService extends IInputMethodManager.Stub
                 }
             }
             if (!enabledImeFound) {
-                Slog.i(TAG, "All the enabled IMEs are gone. Reset default enabled IMEs.");
+                if (DEBUG) {
+                    Slog.i(TAG, "All the enabled IMEs are gone. Reset default enabled IMEs.");
+                }
                 resetDefaultEnabledIme = true;
                 resetSelectedInputMethodAndSubtypeLocked("");
             }