StrictMode: gather and return violating stacks in Binder replies

Now, when Thread A has a strict mode policy in effect and does a
Binder call to Thread B (most likely in another process), the strict
mode policy is passed along, but with the GATHER penalty bit set which
overrides other policies and instead gathers all offending stack
traces to a threadlocal which are then written back in the Parcel's
reply header.

Change-Id: I7d4497032a0609b37b1a2a15855f5c929ba0584d
diff --git a/core/java/android/app/ApplicationErrorReport.java b/core/java/android/app/ApplicationErrorReport.java
index 9834c4c..6981cd6 100644
--- a/core/java/android/app/ApplicationErrorReport.java
+++ b/core/java/android/app/ApplicationErrorReport.java
@@ -27,6 +27,7 @@
 import android.os.SystemProperties;
 import android.provider.Settings;
 import android.util.Printer;
+
 import java.io.PrintWriter;
 import java.io.StringWriter;
 
diff --git a/core/java/android/database/DatabaseUtils.java b/core/java/android/database/DatabaseUtils.java
index 9bfbb74..66406ca 100644
--- a/core/java/android/database/DatabaseUtils.java
+++ b/core/java/android/database/DatabaseUtils.java
@@ -108,7 +108,7 @@
      * @see Parcel#readException
      */
     public static final void readExceptionFromParcel(Parcel reply) {
-        int code = reply.readInt();
+        int code = reply.readExceptionCode();
         if (code == 0) return;
         String msg = reply.readString();
         DatabaseUtils.readExceptionFromParcel(reply, msg, code);
@@ -116,7 +116,7 @@
 
     public static void readExceptionWithFileNotFoundExceptionFromParcel(
             Parcel reply) throws FileNotFoundException {
-        int code = reply.readInt();
+        int code = reply.readExceptionCode();
         if (code == 0) return;
         String msg = reply.readString();
         if (code == 1) {
@@ -128,7 +128,7 @@
 
     public static void readExceptionWithOperationApplicationExceptionFromParcel(
             Parcel reply) throws OperationApplicationException {
-        int code = reply.readInt();
+        int code = reply.readExceptionCode();
         if (code == 0) return;
         String msg = reply.readString();
         if (code == 10) {
diff --git a/core/java/android/os/Binder.java b/core/java/android/os/Binder.java
index 4c40982..59b8274 100644
--- a/core/java/android/os/Binder.java
+++ b/core/java/android/os/Binder.java
@@ -299,6 +299,8 @@
     
     private native final void init();
     private native final void destroy();
+
+    // Entry point from android_util_Binder.cpp's onTransact
     private boolean execTransact(int code, int dataObj, int replyObj,
             int flags) {
         Parcel data = Parcel.obtain(dataObj);
diff --git a/core/java/android/os/Parcel.java b/core/java/android/os/Parcel.java
index 8ad600c..bfe3b60 100644
--- a/core/java/android/os/Parcel.java
+++ b/core/java/android/os/Parcel.java
@@ -176,6 +176,7 @@
  */
 public final class Parcel {
     private static final boolean DEBUG_RECYCLE = false;
+    private static final String TAG = "Parcel";
 
     @SuppressWarnings({"UnusedDeclaration"})
     private int mObject; // used by native code
@@ -214,12 +215,14 @@
     private static final int VAL_BOOLEANARRAY = 23;
     private static final int VAL_CHARSEQUENCEARRAY = 24;
 
+    // The initial int32 in a Binder call's reply Parcel header:
     private static final int EX_SECURITY = -1;
     private static final int EX_BAD_PARCELABLE = -2;
     private static final int EX_ILLEGAL_ARGUMENT = -3;
     private static final int EX_NULL_POINTER = -4;
     private static final int EX_ILLEGAL_STATE = -5;
-    
+    private static final int EX_HAS_REPLY_HEADER = -128;  // special; see below
+
     public final static Parcelable.Creator<String> STRING_CREATOR
              = new Parcelable.Creator<String>() {
         public String createFromParcel(Parcel source) {
@@ -1216,7 +1219,31 @@
      * @see #readException
      */
     public final void writeNoException() {
-        writeInt(0);
+        // Despite the name of this function ("write no exception"),
+        // it should instead be thought of as "write the RPC response
+        // header", but because this function name is written out by
+        // the AIDL compiler, we're not going to rename it.
+        //
+        // The response header, in the non-exception case (see also
+        // writeException above, also called by the AIDL compiler), is
+        // either a 0 (the default case), or EX_HAS_REPLY_HEADER if
+        // StrictMode has gathered up violations that have occurred
+        // during a Binder call, in which case we write out the number
+        // of violations and their details, serialized, before the
+        // actual RPC respons data.  The receiving end of this is
+        // readException(), below.
+        if (StrictMode.hasGatheredViolations()) {
+            writeInt(EX_HAS_REPLY_HEADER);
+            final int sizePosition = dataPosition();
+            writeInt(0);  // total size of fat header, to be filled in later
+            StrictMode.writeGatheredViolationsToParcel(this);
+            final int payloadPosition = dataPosition();
+            setDataPosition(sizePosition);
+            writeInt(payloadPosition - sizePosition);  // header size
+            setDataPosition(payloadPosition);
+        } else {
+            writeInt(0);
+        }
     }
 
     /**
@@ -1229,10 +1256,44 @@
      * @see #writeNoException
      */
     public final void readException() {
+        int code = readExceptionCode();
+        if (code != 0) {
+            String msg = readString();
+            readException(code, msg);
+        }
+    }
+
+    /**
+     * Parses the header of a Binder call's response Parcel and
+     * returns the exception code.  Deals with lite or fat headers.
+     * In the common successful case, this header is generally zero.
+     * In less common cases, it's a small negative number and will be
+     * followed by an error string.
+     *
+     * This exists purely for android.database.DatabaseUtils and
+     * insulating it from having to handle fat headers as returned by
+     * e.g. StrictMode-induced RPC responses.
+     *
+     * @hide
+     */
+    public final int readExceptionCode() {
         int code = readInt();
-        if (code == 0) return;
-        String msg = readString();
-        readException(code, msg);
+        if (code == EX_HAS_REPLY_HEADER) {
+            int headerSize = readInt();
+            if (headerSize == 0) {
+                Log.e(TAG, "Unexpected zero-sized Parcel reply header.");
+            } else {
+                // Currently the only thing in the header is StrictMode stacks,
+                // but discussions around event/RPC tracing suggest we might
+                // put that here too.  If so, switch on sub-header tags here.
+                // But for now, just parse out the StrictMode stuff.
+                StrictMode.readAndHandleBinderCallViolations(this);
+            }
+            // And fat response headers are currently only used when
+            // there are no exceptions, so return no error:
+            return 0;
+        }
+        return code;
     }
 
     /**
@@ -1872,13 +1933,13 @@
                     creator = (Parcelable.Creator)f.get(null);
                 }
                 catch (IllegalAccessException e) {
-                    Log.e("Parcel", "Class not found when unmarshalling: "
+                    Log.e(TAG, "Class not found when unmarshalling: "
                                         + name + ", e: " + e);
                     throw new BadParcelableException(
                             "IllegalAccessException when unmarshalling: " + name);
                 }
                 catch (ClassNotFoundException e) {
-                    Log.e("Parcel", "Class not found when unmarshalling: "
+                    Log.e(TAG, "Class not found when unmarshalling: "
                                         + name + ", e: " + e);
                     throw new BadParcelableException(
                             "ClassNotFoundException when unmarshalling: " + name);
@@ -1983,7 +2044,7 @@
         if (DEBUG_RECYCLE) {
             mStack = new RuntimeException();
         }
-        //Log.i("Parcel", "Initializing obj=0x" + Integer.toHexString(obj), mStack);
+        //Log.i(TAG, "Initializing obj=0x" + Integer.toHexString(obj), mStack);
         init(obj);
     }
 
@@ -1991,7 +2052,7 @@
     protected void finalize() throws Throwable {
         if (DEBUG_RECYCLE) {
             if (mStack != null) {
-                Log.w("Parcel", "Client did not call Parcel.recycle()", mStack);
+                Log.w(TAG, "Client did not call Parcel.recycle()", mStack);
             }
         }
         destroy();
@@ -2015,7 +2076,7 @@
         ClassLoader loader) {
         while (N > 0) {
             Object value = readValue(loader);
-            //Log.d("Parcel", "Unmarshalling value=" + value);
+            //Log.d(TAG, "Unmarshalling value=" + value);
             outVal.add(value);
             N--;
         }
@@ -2025,7 +2086,7 @@
         ClassLoader loader) {
         for (int i = 0; i < N; i++) {
             Object value = readValue(loader);
-            //Log.d("Parcel", "Unmarshalling value=" + value);
+            //Log.d(TAG, "Unmarshalling value=" + value);
             outVal[i] = value;
         }
     }
@@ -2035,7 +2096,7 @@
         while (N > 0) {
             int key = readInt();
             Object value = readValue(loader);
-            //Log.i("Parcel", "Unmarshalling key=" + key + " value=" + value);
+            //Log.i(TAG, "Unmarshalling key=" + key + " value=" + value);
             outVal.append(key, value);
             N--;
         }
@@ -2046,7 +2107,7 @@
         while (N > 0) {
             int key = readInt();
             boolean value = this.readByte() == 1;
-            //Log.i("Parcel", "Unmarshalling key=" + key + " value=" + value);
+            //Log.i(TAG, "Unmarshalling key=" + key + " value=" + value);
             outVal.append(key, value);
             N--;
         }
diff --git a/core/java/android/os/StrictMode.java b/core/java/android/os/StrictMode.java
index f7ad884..312bca1 100644
--- a/core/java/android/os/StrictMode.java
+++ b/core/java/android/os/StrictMode.java
@@ -23,6 +23,9 @@
 
 import dalvik.system.BlockGuard;
 
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.util.ArrayList;
 import java.util.HashMap;
 
 /**
@@ -31,6 +34,7 @@
  */
 public final class StrictMode {
     private static final String TAG = "StrictMode";
+    private static final boolean LOG_V = false;
 
     // Only log a duplicate stack trace to the logs every second.
     private static final long MIN_LOG_INTERVAL_MS = 1000;
@@ -86,6 +90,19 @@
             PENALTY_DROPBOX | PENALTY_DEATH;
 
     /**
+     * Log of strict mode violation stack traces that have occurred
+     * during a Binder call, to be serialized back later to the caller
+     * via Parcel.writeNoException() (amusingly) where the caller can
+     * choose how to react.
+     */
+    private static ThreadLocal<ArrayList<ApplicationErrorReport.CrashInfo>> gatheredViolations =
+            new ThreadLocal<ArrayList<ApplicationErrorReport.CrashInfo>>() {
+        @Override protected ArrayList<ApplicationErrorReport.CrashInfo> initialValue() {
+            return new ArrayList<ApplicationErrorReport.CrashInfo>(1);
+        }
+    };
+
+    /**
      * Sets the policy for what actions the current thread is denied,
      * as well as the penalty for violating the policy.
      *
@@ -118,6 +135,24 @@
         }
     }
 
+    private static class StrictModeNetworkViolation extends BlockGuard.BlockGuardPolicyException {
+        public StrictModeNetworkViolation(int policyMask) {
+            super(policyMask, DISALLOW_NETWORK);
+        }
+    }
+
+    private static class StrictModeDiskReadViolation extends BlockGuard.BlockGuardPolicyException {
+        public StrictModeDiskReadViolation(int policyMask) {
+            super(policyMask, DISALLOW_DISK_READ);
+        }
+    }
+
+    private static class StrictModeDiskWriteViolation extends BlockGuard.BlockGuardPolicyException {
+        public StrictModeDiskWriteViolation(int policyMask) {
+            super(policyMask, DISALLOW_DISK_WRITE);
+        }
+    }
+
     /**
      * Returns the bitmask of the current thread's blocking policy.
      *
@@ -127,6 +162,52 @@
         return BlockGuard.getThreadPolicy().getPolicyMask();
     }
 
+    /**
+     * Parses the BlockGuard policy mask out from the Exception's
+     * getMessage() String value.  Kinda gross, but least
+     * invasive.  :/
+     *
+     * Input is of form "policy=137 violation=64"
+     *
+     * Returns 0 on failure, which is a valid policy, but not a
+     * valid policy during a violation (else there must've been
+     * some policy in effect to violate).
+     */
+    private static int parsePolicyFromMessage(String message) {
+        if (message == null || !message.startsWith("policy=")) {
+            return 0;
+        }
+        int spaceIndex = message.indexOf(' ');
+        if (spaceIndex == -1) {
+            return 0;
+        }
+        String policyString = message.substring(7, spaceIndex);
+        try {
+            return Integer.valueOf(policyString).intValue();
+        } catch (NumberFormatException e) {
+            return 0;
+        }
+    }
+
+    /**
+     * Like parsePolicyFromMessage(), but returns the violation.
+     */
+    private static int parseViolationFromMessage(String message) {
+        if (message == null) {
+            return 0;
+        }
+        int violationIndex = message.indexOf("violation=");
+        if (violationIndex == -1) {
+            return 0;
+        }
+        String violationString = message.substring(violationIndex + 10);
+        try {
+            return Integer.valueOf(violationString).intValue();
+        } catch (NumberFormatException e) {
+            return 0;
+        }
+    }
+
     private static class AndroidBlockGuardPolicy implements BlockGuard.Policy {
         private int mPolicyMask;
 
@@ -139,6 +220,11 @@
             mPolicyMask = policyMask;
         }
 
+        @Override
+        public String toString() {
+            return "AndroidBlockGuardPolicy; mPolicyMask=" + mPolicyMask;
+        }
+
         // Part of BlockGuard.Policy interface:
         public int getPolicyMask() {
             return mPolicyMask;
@@ -149,7 +235,7 @@
             if ((mPolicyMask & DISALLOW_DISK_WRITE) == 0) {
                 return;
             }
-            handleViolation(DISALLOW_DISK_WRITE);
+            startHandlingViolationException(new StrictModeDiskWriteViolation(mPolicyMask));
         }
 
         // Part of BlockGuard.Policy interface:
@@ -157,7 +243,7 @@
             if ((mPolicyMask & DISALLOW_DISK_READ) == 0) {
                 return;
             }
-            handleViolation(DISALLOW_DISK_READ);
+            startHandlingViolationException(new StrictModeDiskReadViolation(mPolicyMask));
         }
 
         // Part of BlockGuard.Policy interface:
@@ -165,17 +251,23 @@
             if ((mPolicyMask & DISALLOW_NETWORK) == 0) {
                 return;
             }
-            handleViolation(DISALLOW_NETWORK);
+            startHandlingViolationException(new StrictModeNetworkViolation(mPolicyMask));
         }
 
         public void setPolicyMask(int policyMask) {
             mPolicyMask = policyMask;
         }
 
-        private void handleViolation(int violationBit) {
-            final BlockGuard.BlockGuardPolicyException violation =
-                    new BlockGuard.BlockGuardPolicyException(mPolicyMask, violationBit);
-            violation.fillInStackTrace();
+        // Start handling a violation that just started and hasn't
+        // actually run yet (e.g. no disk write or network operation
+        // has yet occurred).  This sees if we're in an event loop
+        // thread and, if so, uses it to roughly measure how long the
+        // violation took.
+        void startHandlingViolationException(BlockGuard.BlockGuardPolicyException e) {
+            e.fillInStackTrace();
+            final ApplicationErrorReport.CrashInfo crashInfo = new ApplicationErrorReport.CrashInfo(e);
+            crashInfo.durationMillis = -1;  // unknown
+            final int savedPolicy = mPolicyMask;
 
             Looper looper = Looper.myLooper();
             if (looper == null) {
@@ -183,38 +275,50 @@
                 // violation takes place.  This case should be rare,
                 // as most users will care about timing violations
                 // that happen on their main UI thread.
-                handleViolationWithTime(violation, -1L /* no time */);
+                handleViolation(crashInfo, savedPolicy);
             } else {
                 MessageQueue queue = Looper.myQueue();
                 final long violationTime = SystemClock.uptimeMillis();
                 queue.addIdleHandler(new MessageQueue.IdleHandler() {
                         public boolean queueIdle() {
                             long afterViolationTime = SystemClock.uptimeMillis();
-                            handleViolationWithTime(violation, afterViolationTime - violationTime);
+                            crashInfo.durationMillis = afterViolationTime - violationTime;
+                            handleViolation(crashInfo, savedPolicy);
                             return false;  // remove this idle handler from the array
                         }
                     });
             }
+
         }
 
-        private void handleViolationWithTime(
-            BlockGuard.BlockGuardPolicyException violation,
-            long durationMillis) {
+        // Note: It's possible (even quite likely) that the
+        // thread-local policy mask has changed from the time the
+        // violation fired and now (after the violating code ran) due
+        // to people who push/pop temporary policy in regions of code,
+        // hence the policy being passed around.
+        void handleViolation(
+            final ApplicationErrorReport.CrashInfo crashInfo,
+            int policy) {
+            if (crashInfo.stackTrace == null) {
+                Log.d(TAG, "unexpected null stacktrace");
+                return;
+            }
 
-            // It's possible (even quite likely) that mPolicyMask has
-            // changed from the time the violation fired and now
-            // (after the violating code ran) due to people who
-            // push/pop temporary policy in regions of code.  So use
-            // the old policy here.
-            int policy = violation.getPolicy();
-
-            // Not _really_ a Crash, but we use the same data structure...
-            ApplicationErrorReport.CrashInfo crashInfo =
-                    new ApplicationErrorReport.CrashInfo(violation);
-            crashInfo.durationMillis = durationMillis;
+            if (LOG_V) Log.d(TAG, "handleViolation; policy=" + policy);
 
             if ((policy & PENALTY_GATHER) != 0) {
-                Log.d(TAG, "StrictMode violation via Binder call; ignoring for now.");
+                ArrayList<ApplicationErrorReport.CrashInfo> violations = gatheredViolations.get();
+                if (violations.size() >= 5) {
+                    // Too many.  In a loop or something?  Don't gather them all.
+                    return;
+                }
+                for (ApplicationErrorReport.CrashInfo previous : violations) {
+                    if (crashInfo.stackTrace.equals(previous.stackTrace)) {
+                        // Duplicate. Don't log.
+                        return;
+                    }
+                }
+                violations.add(crashInfo);
                 return;
             }
 
@@ -231,11 +335,11 @@
 
             if ((policy & PENALTY_LOG) != 0 &&
                 timeSinceLastViolationMillis > MIN_LOG_INTERVAL_MS) {
-                if (durationMillis != -1) {
-                    Log.d(TAG, "StrictMode policy violation; ~duration=" + durationMillis + " ms",
-                          violation);
+                if (crashInfo.durationMillis != -1) {
+                    Log.d(TAG, "StrictMode policy violation; ~duration=" +
+                          crashInfo.durationMillis + " ms: " + crashInfo.stackTrace);
                 } else {
-                    Log.d(TAG, "StrictMode policy violation.", violation);
+                    Log.d(TAG, "StrictMode policy violation: " + crashInfo.stackTrace);
                 }
             }
 
@@ -255,7 +359,8 @@
             }
 
             if (violationMask != 0) {
-                violationMask |= violation.getPolicyViolation();
+                int violationBit = parseViolationFromMessage(crashInfo.exceptionMessage);
+                violationMask |= violationBit;
                 final int savedPolicy = getThreadBlockingPolicy();
                 try {
                     // First, remove any policy before we call into the Activity Manager,
@@ -267,7 +372,7 @@
                     ActivityManagerNative.getDefault().handleApplicationStrictModeViolation(
                         RuntimeInit.getApplicationObject(),
                         violationMask,
-                        new ApplicationErrorReport.CrashInfo(violation));
+                        crashInfo);
                 } catch (RemoteException e) {
                     Log.e(TAG, "RemoteException trying to handle StrictMode violation", e);
                 } finally {
@@ -285,6 +390,68 @@
     }
 
     /**
+     * Called from Parcel.writeNoException()
+     */
+    /* package */ static boolean hasGatheredViolations() {
+        return !gatheredViolations.get().isEmpty();
+    }
+
+    /**
+     * Called from Parcel.writeNoException()
+     */
+    /* package */ static void writeGatheredViolationsToParcel(Parcel p) {
+        ArrayList<ApplicationErrorReport.CrashInfo> violations = gatheredViolations.get();
+        p.writeInt(violations.size());
+        for (int i = 0; i < violations.size(); ++i) {
+            violations.get(i).writeToParcel(p, 0 /* unused flags? */);
+        }
+
+        if (LOG_V) Log.d(TAG, "wrote violations to response parcel; num=" + violations.size());
+        violations.clear();
+    }
+
+    private static class LogStackTrace extends Exception {}
+
+    /**
+     * Called from Parcel.readException() when the exception is EX_STRICT_MODE_VIOLATIONS,
+     * we here read back all the encoded violations.
+     */
+    /* package */ static void readAndHandleBinderCallViolations(Parcel p) {
+        // Our own stack trace to append
+        Exception e = new LogStackTrace();
+        StringWriter sw = new StringWriter();
+        e.printStackTrace(new PrintWriter(sw));
+        String ourStack = sw.toString();
+
+        int policyMask = getThreadBlockingPolicy();
+
+        int numViolations = p.readInt();
+        for (int i = 0; i < numViolations; ++i) {
+            if (LOG_V) Log.d(TAG, "strict mode violation stacks read from binder call.  i=" + i);
+            ApplicationErrorReport.CrashInfo crashInfo = new ApplicationErrorReport.CrashInfo(p);
+            crashInfo.stackTrace += "# via Binder call with stack:\n" + ourStack;
+
+            // Unlike the in-process violations in which case we
+            // trigger an error _before_ the thing occurs, in this
+            // case the violating thing has already occurred, so we
+            // can't use our heuristic of waiting for the next event
+            // loop idle cycle to measure the approximate violation
+            // duration.  Instead, just skip that step and use -1
+            // (unknown duration) for now.
+            // TODO: keep a thread-local on remote process of first
+            // violation time's uptimeMillis, and when writing that
+            // back out in Parcel reply, include in the header the
+            // violation time and use it here.
+            crashInfo.durationMillis = -1;
+
+            BlockGuard.Policy policy = BlockGuard.getThreadPolicy();
+            if (policy instanceof AndroidBlockGuardPolicy) {
+                ((AndroidBlockGuardPolicy) policy).handleViolation(crashInfo, policyMask);
+            }
+        }
+    }
+
+    /**
      * Called from android_util_Binder.cpp's
      * android_os_Parcel_enforceInterface when an incoming Binder call
      * requires changing the StrictMode policy mask.  The role of this
diff --git a/libs/binder/Parcel.cpp b/libs/binder/Parcel.cpp
index bed893a..60babad 100644
--- a/libs/binder/Parcel.cpp
+++ b/libs/binder/Parcel.cpp
@@ -51,6 +51,9 @@
 // Note: must be kept in sync with android/os/StrictMode.java's PENALTY_GATHER
 #define STRICT_MODE_PENALTY_GATHER 0x100
 
+// Note: must be kept in sync with android/os/Parcel.java's EX_HAS_REPLY_HEADER
+#define EX_HAS_REPLY_HEADER -128
+
 // XXX This can be made public if we want to provide
 // support for typed data.
 struct small_flat_data
@@ -959,7 +962,15 @@
 int32_t Parcel::readExceptionCode() const
 {
   int32_t exception_code = readAligned<int32_t>();
-  // TODO: skip over the response header here, once that's in.
+  if (exception_code == EX_HAS_REPLY_HEADER) {
+    int32_t header_size = readAligned<int32_t>();
+    // Skip over fat responses headers.  Not used (or propagated) in
+    // native code
+    setDataPosition(dataPosition() + header_size);
+    // And fat response headers are currently only used when there are no
+    // exceptions, so return no error:
+    return 0;
+  }
   return exception_code;
 }