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

Commit 8d051721 authored by Dianne Hackborn's avatar Dianne Hackborn
Browse files

More work on issue #17656716: Unhandled exception in Window Manager

Fix Slog.wtf to not acquire the activity manager lock in its code
path, so that it can never deadlock.  This was the original intention
of it, but part was missed.

Now we can put back in the code to detect when strict mode data is
getting large (a little more targeted now to the actual problem),
and use Slog.wtf to report it.  And as a bonus, when this happens
we will now clear all of the collected violations, to avoid getting
in to the bad case where IPCs start failing.  So this should be
good enough for L to fix the problem, with wtf reports for us to
see if the underlying issue is still happening.

Finally, switch a butch of stuff in the system process from Log.wtf
to Slog.wtf, since many of those are deadlocks waiting to happen.

Oh and fix a crash in the settings provider I noticed in APR.

Change-Id: I307d51b7a4db238fd1e5fe2f3f9bf1b9c6f1c041
parent f178591f
Loading
Loading
Loading
Loading
+19 −4
Original line number Diff line number Diff line
@@ -1725,10 +1725,25 @@ public final class StrictMode {
        for (int i = 0; i < numViolations; ++i) {
            if (LOG_V) Log.d(TAG, "strict mode violation stacks read from binder call.  i=" + i);
            ViolationInfo info = new ViolationInfo(p, !currentlyGathering);
            if (info.crashInfo.stackTrace.length() > 5000) {
                RuntimeException here = new RuntimeException("here");
                here.fillInStackTrace();
                Slog.w(TAG, "Stack is getting large: " + info.crashInfo.stackTrace, here);
            if (info.crashInfo.stackTrace.length() > 10000) {
                // 10000 characters is way too large for this to be any sane kind of
                // strict mode collection of stacks.  We've had a problem where we leave
                // strict mode violations associated with the thread, and it keeps tacking
                // more and more stacks on to the violations.  Looks like we're in this casse,
                // so we'll report it and bail on all of the current strict mode violations
                // we currently are maintaining for this thread.
                // First, drain the remaining violations from the parcel.
                while (i < numViolations) {
                    info = new ViolationInfo(p, !currentlyGathering);
                    i++;
                }
                // Next clear out all gathered violations.
                clearGatheredViolations();
                // Now report the problem.
                Slog.wtfStack(TAG, "Stack is too large: numViolations=" + numViolations
                        + " policy=#" + Integer.toHexString(policyMask)
                        + " front=" + info.crashInfo.stackTrace.substring(256));
                return;
            }
            info.crashInfo.stackTrace += "# via Binder call with stack:\n" + ourStack;
            BlockGuard.Policy policy = BlockGuard.getThreadPolicy();
+20 −0
Original line number Diff line number Diff line
@@ -73,18 +73,38 @@ public final class Slog {
                msg + '\n' + Log.getStackTraceString(tr));
    }

    /**
     * Like {@link Log#wtf(String, String)}, but will never cause the caller to crash, and
     * will always be handled asynchronously.  Primarily for use by coding running within
     * the system process.
     */
    public static int wtf(String tag, String msg) {
        return Log.wtf(Log.LOG_ID_SYSTEM, tag, msg, null, false, true);
    }

    /**
     * Like {@link Log#wtfStack(String, String)}, but will never cause the caller to crash, and
     * will always be handled asynchronously.  Primarily for use by coding running within
     * the system process.
     */
    public static int wtfStack(String tag, String msg) {
        return Log.wtf(Log.LOG_ID_SYSTEM, tag, msg, null, true, true);
    }

    /**
     * Like {@link Log#wtf(String, Throwable)}, but will never cause the caller to crash,
     * and will always be handled asynchronously.  Primarily for use by coding running within
     * the system process.
     */
    public static int wtf(String tag, Throwable tr) {
        return Log.wtf(Log.LOG_ID_SYSTEM, tag, tr.getMessage(), tr, false, true);
    }

    /**
     * Like {@link Log#wtf(String, String, Throwable)}, but will never cause the caller to crash,
     * and will always be handled asynchronously.  Primarily for use by coding running within
     * the system process.
     */
    public static int wtf(String tag, String msg, Throwable tr) {
        return Log.wtf(Log.LOG_ID_SYSTEM, tag, msg, tr, false, true);
    }
+45 −14
Original line number Diff line number Diff line
@@ -351,8 +351,11 @@ public class SettingsProvider extends ContentProvider {
        }

        public void onEvent(int event, String path) {
            int modsInFlight = sKnownMutationsInFlight.get(mUserHandle).get();
            if (modsInFlight > 0) {
            final AtomicInteger mutationCount;
            synchronized (SettingsProvider.this) {
                mutationCount = sKnownMutationsInFlight.get(mUserHandle);
            }
            if (mutationCount != null && mutationCount.get() > 0) {
                // our own modification.
                return;
            }
@@ -952,8 +955,13 @@ public class SettingsProvider extends ContentProvider {
        checkWritePermissions(args);
        SettingsCache cache = cacheForTable(callingUser, args.table);

        final AtomicInteger mutationCount = sKnownMutationsInFlight.get(callingUser);
        final AtomicInteger mutationCount;
        synchronized (this) {
            mutationCount = sKnownMutationsInFlight.get(callingUser);
        }
        if (mutationCount != null) {
            mutationCount.incrementAndGet();
        }
        DatabaseHelper dbH = getOrEstablishDatabase(
                TABLE_GLOBAL.equals(args.table) ? UserHandle.USER_OWNER : callingUser);
        SQLiteDatabase db = dbH.getWritableDatabase();
@@ -969,8 +977,10 @@ public class SettingsProvider extends ContentProvider {
            db.setTransactionSuccessful();
        } finally {
            db.endTransaction();
            if (mutationCount != null) {
                mutationCount.decrementAndGet();
            }
        }

        sendNotify(uri, callingUser);
        return values.length;
@@ -1105,12 +1115,19 @@ public class SettingsProvider extends ContentProvider {
            return Uri.withAppendedPath(url, name);
        }

        final AtomicInteger mutationCount = sKnownMutationsInFlight.get(desiredUserHandle);
        final AtomicInteger mutationCount;
        synchronized (this) {
            mutationCount = sKnownMutationsInFlight.get(callingUser);
        }
        if (mutationCount != null) {
            mutationCount.incrementAndGet();
        }
        DatabaseHelper dbH = getOrEstablishDatabase(desiredUserHandle);
        SQLiteDatabase db = dbH.getWritableDatabase();
        final long rowId = db.insert(args.table, null, initialValues);
        if (mutationCount != null) {
            mutationCount.decrementAndGet();
        }
        if (rowId <= 0) return null;

        SettingsCache.populate(cache, initialValues);  // before we notify
@@ -1137,12 +1154,19 @@ public class SettingsProvider extends ContentProvider {
        }
        checkWritePermissions(args);

        final AtomicInteger mutationCount = sKnownMutationsInFlight.get(callingUser);
        final AtomicInteger mutationCount;
        synchronized (this) {
            mutationCount = sKnownMutationsInFlight.get(callingUser);
        }
        if (mutationCount != null) {
            mutationCount.incrementAndGet();
        }
        DatabaseHelper dbH = getOrEstablishDatabase(callingUser);
        SQLiteDatabase db = dbH.getWritableDatabase();
        int count = db.delete(args.table, args.where, args.args);
        if (mutationCount != null) {
            mutationCount.decrementAndGet();
        }
        if (count > 0) {
            invalidateCache(callingUser, args.table);  // before we notify
            sendNotify(url, callingUser);
@@ -1170,12 +1194,19 @@ public class SettingsProvider extends ContentProvider {
        checkWritePermissions(args);
        checkUserRestrictions(initialValues.getAsString(Settings.Secure.NAME), callingUser);

        final AtomicInteger mutationCount = sKnownMutationsInFlight.get(callingUser);
        final AtomicInteger mutationCount;
        synchronized (this) {
            mutationCount = sKnownMutationsInFlight.get(callingUser);
        }
        if (mutationCount != null) {
            mutationCount.incrementAndGet();
        }
        DatabaseHelper dbH = getOrEstablishDatabase(callingUser);
        SQLiteDatabase db = dbH.getWritableDatabase();
        int count = db.update(args.table, initialValues, args.where, args.args);
        if (mutationCount != null) {
            mutationCount.decrementAndGet();
        }
        if (count > 0) {
            invalidateCache(callingUser, args.table);  // before we notify
            sendNotify(url, callingUser);
+24 −18
Original line number Diff line number Diff line
@@ -27,7 +27,6 @@ import static com.android.internal.util.XmlUtils.writeBooleanAttribute;
import static com.android.internal.util.XmlUtils.writeIntAttribute;
import static com.android.internal.util.XmlUtils.writeLongAttribute;
import static com.android.server.Watchdog.NATIVE_STACKS_OF_INTEREST;
import static com.android.server.am.ActivityRecord.HOME_ACTIVITY_TYPE;
import static org.xmlpull.v1.XmlPullParser.END_DOCUMENT;
import static org.xmlpull.v1.XmlPullParser.START_TAG;
import static com.android.server.am.ActivityStackSupervisor.HOME_STACK_ID;
@@ -4958,7 +4957,7 @@ public final class ActivityManagerService extends ActivityManagerNative
                        }
                    }
                } catch (InterruptedException e) {
                    Log.wtf(TAG, e);
                    Slog.wtf(TAG, e);
                }
            }
@@ -4998,7 +4997,7 @@ public final class ActivityManagerService extends ActivityManagerNative
                                observer.wait(200);  // Wait for write-close, give up after 200msec
                            }
                        } catch (InterruptedException e) {
                            Log.wtf(TAG, e);
                            Slog.wtf(TAG, e);
                        }
                    }
@@ -7918,9 +7917,9 @@ public final class ActivityManagerService extends ActivityManagerNative
        } catch (FileNotFoundException e) {
            // Missing grants is okay
        } catch (IOException e) {
            Log.wtf(TAG, "Failed reading Uri grants", e);
            Slog.wtf(TAG, "Failed reading Uri grants", e);
        } catch (XmlPullParserException e) {
            Log.wtf(TAG, "Failed reading Uri grants", e);
            Slog.wtf(TAG, "Failed reading Uri grants", e);
        } finally {
            IoUtils.closeQuietly(fis);
        }
@@ -11713,17 +11712,10 @@ public final class ActivityManagerService extends ActivityManagerNative
     * @param crashInfo describing the context of the error
     * @return true if the process should exit immediately (WTF is fatal)
     */
    public boolean handleApplicationWtf(IBinder app, final String tag, boolean system,
    public boolean handleApplicationWtf(final IBinder app, final String tag, boolean system,
            final ApplicationErrorReport.CrashInfo crashInfo) {
        final ProcessRecord r = findAppProcess(app, "WTF");
        final String processName = app == null ? "system_server"
                : (r == null ? "unknown" : r.processName);
        EventLog.writeEvent(EventLogTags.AM_WTF,
                UserHandle.getUserId(Binder.getCallingUid()), Binder.getCallingPid(),
                processName,
                r == null ? -1 : r.info.flags,
                tag, crashInfo.exceptionMessage);
        final int callingUid = Binder.getCallingUid();
        final int callingPid = Binder.getCallingPid();
        if (system) {
            // If this is coming from the system, we could very well have low-level
@@ -11731,14 +11723,14 @@ public final class ActivityManagerService extends ActivityManagerNative
            // never want this to become fatal, so there is that too.
            mHandler.post(new Runnable() {
                @Override public void run() {
                    addErrorToDropBox("wtf", r, processName, null, null, tag, null, null,
                            crashInfo);
                    handleApplicationWtfInner(callingUid, callingPid, app, tag, crashInfo);
                }
            });
            return false;
        }
        addErrorToDropBox("wtf", r, processName, null, null, tag, null, null, crashInfo);
        final ProcessRecord r = handleApplicationWtfInner(callingUid, callingPid, app, tag,
                crashInfo);
        if (r != null && r.pid != Process.myPid() &&
                Settings.Global.getInt(mContext.getContentResolver(),
@@ -11750,6 +11742,20 @@ public final class ActivityManagerService extends ActivityManagerNative
        }
    }
    ProcessRecord handleApplicationWtfInner(int callingUid, int callingPid, IBinder app, String tag,
            final ApplicationErrorReport.CrashInfo crashInfo) {
        final ProcessRecord r = findAppProcess(app, "WTF");
        final String processName = app == null ? "system_server"
                : (r == null ? "unknown" : r.processName);
        EventLog.writeEvent(EventLogTags.AM_WTF, UserHandle.getUserId(callingUid), callingPid,
                processName, r == null ? -1 : r.info.flags, tag, crashInfo.exceptionMessage);
        addErrorToDropBox("wtf", r, processName, null, null, tag, null, null, crashInfo);
        return r;
    }
    /**
     * @param app object of some object (as stored in {@link com.android.internal.os.RuntimeInit})
     * @return the corresponding {@link ProcessRecord} object, or null if none could be found
+1 −1
Original line number Diff line number Diff line
@@ -901,7 +901,7 @@ public final class BroadcastQueue {
                    Slog.w(TAG, "Exception when sending broadcast to "
                          + r.curComponent, e);
                } catch (RuntimeException e) {
                    Log.wtf(TAG, "Failed sending broadcast to "
                    Slog.wtf(TAG, "Failed sending broadcast to "
                            + r.curComponent + " with " + r.intent, e);
                    // If some unexpected exception happened, just skip
                    // this broadcast.  At this point we are not in the call
Loading