Skip to content

Commit 8d05172

Browse files
author
Dianne Hackborn
committed
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
1 parent f178591 commit 8d05172

13 files changed

Lines changed: 140 additions & 62 deletions

File tree

‎core/java/android/os/StrictMode.java‎

Lines changed: 19 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1725,10 +1725,25 @@ private static class LogStackTrace extends Exception {}
17251725
for (int i = 0; i < numViolations; ++i) {
17261726
if (LOG_V) Log.d(TAG, "strict mode violation stacks read from binder call. i=" + i);
17271727
ViolationInfo info = new ViolationInfo(p, !currentlyGathering);
1728-
if (info.crashInfo.stackTrace.length() > 5000) {
1729-
RuntimeException here = new RuntimeException("here");
1730-
here.fillInStackTrace();
1731-
Slog.w(TAG, "Stack is getting large: " + info.crashInfo.stackTrace, here);
1728+
if (info.crashInfo.stackTrace.length() > 10000) {
1729+
// 10000 characters is way too large for this to be any sane kind of
1730+
// strict mode collection of stacks. We've had a problem where we leave
1731+
// strict mode violations associated with the thread, and it keeps tacking
1732+
// more and more stacks on to the violations. Looks like we're in this casse,
1733+
// so we'll report it and bail on all of the current strict mode violations
1734+
// we currently are maintaining for this thread.
1735+
// First, drain the remaining violations from the parcel.
1736+
while (i < numViolations) {
1737+
info = new ViolationInfo(p, !currentlyGathering);
1738+
i++;
1739+
}
1740+
// Next clear out all gathered violations.
1741+
clearGatheredViolations();
1742+
// Now report the problem.
1743+
Slog.wtfStack(TAG, "Stack is too large: numViolations=" + numViolations
1744+
+ " policy=#" + Integer.toHexString(policyMask)
1745+
+ " front=" + info.crashInfo.stackTrace.substring(256));
1746+
return;
17321747
}
17331748
info.crashInfo.stackTrace += "# via Binder call with stack:\n" + ourStack;
17341749
BlockGuard.Policy policy = BlockGuard.getThreadPolicy();

‎core/java/android/util/Slog.java‎

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -73,18 +73,38 @@ public static int e(String tag, String msg, Throwable tr) {
7373
msg + '\n' + Log.getStackTraceString(tr));
7474
}
7575

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

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

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

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

‎packages/SettingsProvider/src/com/android/providers/settings/SettingsProvider.java‎

Lines changed: 45 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -351,8 +351,11 @@ public SettingsFileObserver(int userHandle, String path) {
351351
}
352352

353353
public void onEvent(int event, String path) {
354-
int modsInFlight = sKnownMutationsInFlight.get(mUserHandle).get();
355-
if (modsInFlight > 0) {
354+
final AtomicInteger mutationCount;
355+
synchronized (SettingsProvider.this) {
356+
mutationCount = sKnownMutationsInFlight.get(mUserHandle);
357+
}
358+
if (mutationCount != null && mutationCount.get() > 0) {
356359
// our own modification.
357360
return;
358361
}
@@ -952,8 +955,13 @@ public int bulkInsert(Uri uri, ContentValues[] values) {
952955
checkWritePermissions(args);
953956
SettingsCache cache = cacheForTable(callingUser, args.table);
954957

955-
final AtomicInteger mutationCount = sKnownMutationsInFlight.get(callingUser);
956-
mutationCount.incrementAndGet();
958+
final AtomicInteger mutationCount;
959+
synchronized (this) {
960+
mutationCount = sKnownMutationsInFlight.get(callingUser);
961+
}
962+
if (mutationCount != null) {
963+
mutationCount.incrementAndGet();
964+
}
957965
DatabaseHelper dbH = getOrEstablishDatabase(
958966
TABLE_GLOBAL.equals(args.table) ? UserHandle.USER_OWNER : callingUser);
959967
SQLiteDatabase db = dbH.getWritableDatabase();
@@ -969,7 +977,9 @@ public int bulkInsert(Uri uri, ContentValues[] values) {
969977
db.setTransactionSuccessful();
970978
} finally {
971979
db.endTransaction();
972-
mutationCount.decrementAndGet();
980+
if (mutationCount != null) {
981+
mutationCount.decrementAndGet();
982+
}
973983
}
974984

975985
sendNotify(uri, callingUser);
@@ -1105,12 +1115,19 @@ private Uri insertForUser(Uri url, ContentValues initialValues, int desiredUserH
11051115
return Uri.withAppendedPath(url, name);
11061116
}
11071117

1108-
final AtomicInteger mutationCount = sKnownMutationsInFlight.get(desiredUserHandle);
1109-
mutationCount.incrementAndGet();
1118+
final AtomicInteger mutationCount;
1119+
synchronized (this) {
1120+
mutationCount = sKnownMutationsInFlight.get(callingUser);
1121+
}
1122+
if (mutationCount != null) {
1123+
mutationCount.incrementAndGet();
1124+
}
11101125
DatabaseHelper dbH = getOrEstablishDatabase(desiredUserHandle);
11111126
SQLiteDatabase db = dbH.getWritableDatabase();
11121127
final long rowId = db.insert(args.table, null, initialValues);
1113-
mutationCount.decrementAndGet();
1128+
if (mutationCount != null) {
1129+
mutationCount.decrementAndGet();
1130+
}
11141131
if (rowId <= 0) return null;
11151132

11161133
SettingsCache.populate(cache, initialValues); // before we notify
@@ -1137,12 +1154,19 @@ public int delete(Uri url, String where, String[] whereArgs) {
11371154
}
11381155
checkWritePermissions(args);
11391156

1140-
final AtomicInteger mutationCount = sKnownMutationsInFlight.get(callingUser);
1141-
mutationCount.incrementAndGet();
1157+
final AtomicInteger mutationCount;
1158+
synchronized (this) {
1159+
mutationCount = sKnownMutationsInFlight.get(callingUser);
1160+
}
1161+
if (mutationCount != null) {
1162+
mutationCount.incrementAndGet();
1163+
}
11421164
DatabaseHelper dbH = getOrEstablishDatabase(callingUser);
11431165
SQLiteDatabase db = dbH.getWritableDatabase();
11441166
int count = db.delete(args.table, args.where, args.args);
1145-
mutationCount.decrementAndGet();
1167+
if (mutationCount != null) {
1168+
mutationCount.decrementAndGet();
1169+
}
11461170
if (count > 0) {
11471171
invalidateCache(callingUser, args.table); // before we notify
11481172
sendNotify(url, callingUser);
@@ -1170,12 +1194,19 @@ public int update(Uri url, ContentValues initialValues, String where, String[] w
11701194
checkWritePermissions(args);
11711195
checkUserRestrictions(initialValues.getAsString(Settings.Secure.NAME), callingUser);
11721196

1173-
final AtomicInteger mutationCount = sKnownMutationsInFlight.get(callingUser);
1174-
mutationCount.incrementAndGet();
1197+
final AtomicInteger mutationCount;
1198+
synchronized (this) {
1199+
mutationCount = sKnownMutationsInFlight.get(callingUser);
1200+
}
1201+
if (mutationCount != null) {
1202+
mutationCount.incrementAndGet();
1203+
}
11751204
DatabaseHelper dbH = getOrEstablishDatabase(callingUser);
11761205
SQLiteDatabase db = dbH.getWritableDatabase();
11771206
int count = db.update(args.table, initialValues, args.where, args.args);
1178-
mutationCount.decrementAndGet();
1207+
if (mutationCount != null) {
1208+
mutationCount.decrementAndGet();
1209+
}
11791210
if (count > 0) {
11801211
invalidateCache(callingUser, args.table); // before we notify
11811212
sendNotify(url, callingUser);

‎services/core/java/com/android/server/am/ActivityManagerService.java‎

Lines changed: 24 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,6 @@
2727
import static com.android.internal.util.XmlUtils.writeIntAttribute;
2828
import static com.android.internal.util.XmlUtils.writeLongAttribute;
2929
import static com.android.server.Watchdog.NATIVE_STACKS_OF_INTEREST;
30-
import static com.android.server.am.ActivityRecord.HOME_ACTIVITY_TYPE;
3130
import static org.xmlpull.v1.XmlPullParser.END_DOCUMENT;
3231
import static org.xmlpull.v1.XmlPullParser.START_TAG;
3332
import static com.android.server.am.ActivityStackSupervisor.HOME_STACK_ID;
@@ -4958,7 +4957,7 @@ private static void dumpStackTraces(String tracesPath, ArrayList<Integer> firstP
49584957
}
49594958
}
49604959
} catch (InterruptedException e) {
4961-
Log.wtf(TAG, e);
4960+
Slog.wtf(TAG, e);
49624961
}
49634962
}
49644963

@@ -4998,7 +4997,7 @@ private static void dumpStackTraces(String tracesPath, ArrayList<Integer> firstP
49984997
observer.wait(200); // Wait for write-close, give up after 200msec
49994998
}
50004999
} catch (InterruptedException e) {
5001-
Log.wtf(TAG, e);
5000+
Slog.wtf(TAG, e);
50025001
}
50035002

50045003
}
@@ -7918,9 +7917,9 @@ private void readGrantedUriPermissionsLocked() {
79187917
} catch (FileNotFoundException e) {
79197918
// Missing grants is okay
79207919
} catch (IOException e) {
7921-
Log.wtf(TAG, "Failed reading Uri grants", e);
7920+
Slog.wtf(TAG, "Failed reading Uri grants", e);
79227921
} catch (XmlPullParserException e) {
7923-
Log.wtf(TAG, "Failed reading Uri grants", e);
7922+
Slog.wtf(TAG, "Failed reading Uri grants", e);
79247923
} finally {
79257924
IoUtils.closeQuietly(fis);
79267925
}
@@ -11713,32 +11712,25 @@ public void run() {
1171311712
* @param crashInfo describing the context of the error
1171411713
* @return true if the process should exit immediately (WTF is fatal)
1171511714
*/
11716-
public boolean handleApplicationWtf(IBinder app, final String tag, boolean system,
11715+
public boolean handleApplicationWtf(final IBinder app, final String tag, boolean system,
1171711716
final ApplicationErrorReport.CrashInfo crashInfo) {
11718-
final ProcessRecord r = findAppProcess(app, "WTF");
11719-
final String processName = app == null ? "system_server"
11720-
: (r == null ? "unknown" : r.processName);
11721-
11722-
EventLog.writeEvent(EventLogTags.AM_WTF,
11723-
UserHandle.getUserId(Binder.getCallingUid()), Binder.getCallingPid(),
11724-
processName,
11725-
r == null ? -1 : r.info.flags,
11726-
tag, crashInfo.exceptionMessage);
11717+
final int callingUid = Binder.getCallingUid();
11718+
final int callingPid = Binder.getCallingPid();
1172711719

1172811720
if (system) {
1172911721
// If this is coming from the system, we could very well have low-level
1173011722
// system locks held, so we want to do this all asynchronously. And we
1173111723
// never want this to become fatal, so there is that too.
1173211724
mHandler.post(new Runnable() {
1173311725
@Override public void run() {
11734-
addErrorToDropBox("wtf", r, processName, null, null, tag, null, null,
11735-
crashInfo);
11726+
handleApplicationWtfInner(callingUid, callingPid, app, tag, crashInfo);
1173611727
}
1173711728
});
1173811729
return false;
1173911730
}
1174011731

11741-
addErrorToDropBox("wtf", r, processName, null, null, tag, null, null, crashInfo);
11732+
final ProcessRecord r = handleApplicationWtfInner(callingUid, callingPid, app, tag,
11733+
crashInfo);
1174211734

1174311735
if (r != null && r.pid != Process.myPid() &&
1174411736
Settings.Global.getInt(mContext.getContentResolver(),
@@ -11750,6 +11742,20 @@ public boolean handleApplicationWtf(IBinder app, final String tag, boolean syste
1175011742
}
1175111743
}
1175211744

11745+
ProcessRecord handleApplicationWtfInner(int callingUid, int callingPid, IBinder app, String tag,
11746+
final ApplicationErrorReport.CrashInfo crashInfo) {
11747+
final ProcessRecord r = findAppProcess(app, "WTF");
11748+
final String processName = app == null ? "system_server"
11749+
: (r == null ? "unknown" : r.processName);
11750+
11751+
EventLog.writeEvent(EventLogTags.AM_WTF, UserHandle.getUserId(callingUid), callingPid,
11752+
processName, r == null ? -1 : r.info.flags, tag, crashInfo.exceptionMessage);
11753+
11754+
addErrorToDropBox("wtf", r, processName, null, null, tag, null, null, crashInfo);
11755+
11756+
return r;
11757+
}
11758+
1175311759
/**
1175411760
* @param app object of some object (as stored in {@link com.android.internal.os.RuntimeInit})
1175511761
* @return the corresponding {@link ProcessRecord} object, or null if none could be found

‎services/core/java/com/android/server/am/BroadcastQueue.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -901,7 +901,7 @@ final void processNextBroadcast(boolean fromMsg) {
901901
Slog.w(TAG, "Exception when sending broadcast to "
902902
+ r.curComponent, e);
903903
} catch (RuntimeException e) {
904-
Log.wtf(TAG, "Failed sending broadcast to "
904+
Slog.wtf(TAG, "Failed sending broadcast to "
905905
+ r.curComponent + " with " + r.intent, e);
906906
// If some unexpected exception happened, just skip
907907
// this broadcast. At this point we are not in the call

‎services/core/java/com/android/server/am/UriPermission.java‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -257,7 +257,7 @@ private void addReadOwner(UriPermissionOwner owner) {
257257
*/
258258
void removeReadOwner(UriPermissionOwner owner) {
259259
if (!mReadOwners.remove(owner)) {
260-
Log.wtf(TAG, "Unknown read owner " + owner + " in " + this);
260+
Slog.wtf(TAG, "Unknown read owner " + owner + " in " + this);
261261
}
262262
if (mReadOwners.size() == 0) {
263263
mReadOwners = null;
@@ -282,7 +282,7 @@ private void addWriteOwner(UriPermissionOwner owner) {
282282
*/
283283
void removeWriteOwner(UriPermissionOwner owner) {
284284
if (!mWriteOwners.remove(owner)) {
285-
Log.wtf(TAG, "Unknown write owner " + owner + " in " + this);
285+
Slog.wtf(TAG, "Unknown write owner " + owner + " in " + this);
286286
}
287287
if (mWriteOwners.size() == 0) {
288288
mWriteOwners = null;

‎services/core/java/com/android/server/display/DisplayManagerService.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -448,7 +448,7 @@ private void stopWifiDisplayScanLocked(CallbackRecord record) {
448448
mWifiDisplayAdapter.requestStopScanLocked();
449449
}
450450
} else if (mWifiDisplayScanRequestCount < 0) {
451-
Log.wtf(TAG, "mWifiDisplayScanRequestCount became negative: "
451+
Slog.wtf(TAG, "mWifiDisplayScanRequestCount became negative: "
452452
+ mWifiDisplayScanRequestCount);
453453
mWifiDisplayScanRequestCount = 0;
454454
}

‎services/core/java/com/android/server/pm/PackageInstallerService.java‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -325,9 +325,9 @@ private void readSessionsLocked() {
325325
} catch (FileNotFoundException e) {
326326
// Missing sessions are okay, probably first boot
327327
} catch (IOException e) {
328-
Log.wtf(TAG, "Failed reading install sessions", e);
328+
Slog.wtf(TAG, "Failed reading install sessions", e);
329329
} catch (XmlPullParserException e) {
330-
Log.wtf(TAG, "Failed reading install sessions", e);
330+
Slog.wtf(TAG, "Failed reading install sessions", e);
331331
} finally {
332332
IoUtils.closeQuietly(fis);
333333
}

0 commit comments

Comments
 (0)