在分析手机自动重启时,发现报Abort message: 'JNI ERROR (app bug): global reference table overflow (max=51200)global reference table dump 异常,导致system_server被杀,发生了手机重启。
报错信息如下:
04-21 15:34:08.033 6929 6929 F DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
04-21 15:34:08.033 6929 6929 F DEBUG : Build fingerprint: 'Sonim/XP9904/XP9900:12/10.0.0-02-12.0.0-11.35.10/1671643214:user/release-keys'
04-21 15:34:08.033 6929 6929 F DEBUG : Revision: '0'
04-21 15:34:08.033 6929 6929 F DEBUG : ABI: 'arm64'
04-21 15:34:08.033 6929 6929 F DEBUG : Timestamp: 2023-04-21 15:34:06.205429828-0400
04-21 15:34:08.033 6929 6929 F DEBUG : Process uptime: 0s
04-21 15:34:08.033 6929 6929 F DEBUG : Cmdline: system_server
04-21 15:34:08.033 6929 6929 F DEBUG : pid: 1543, tid: 9759, name: Binder:1543_1E >>> system_server <<<
04-21 15:34:08.033 6929 6929 F DEBUG : uid: 1000
04-21 15:34:08.033 6929 6929 F DEBUG : signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr --------
04-21 15:34:08.033 6929 6929 F DEBUG : Abort message: 'JNI ERROR (app bug): global reference table overflow (max=51200)global reference table dump:
04-21 15:34:08.033 6929 6929 F DEBUG : Last 10 entries (of 51200):
04-21 15:34:08.033 6929 6929 F DEBUG : 51199: 0x12d47618 com.android.internal.os.BinderDeathDispatcher$RecipientsInfo
04-21 15:34:08.033 6929 6929 F DEBUG : 51198: 0x12c99360 com.android.server.am.ServiceRecord
04-21 15:34:08.033 6929 6929 F DEBUG : 51197: 0x12d46bc8 com.android.internal.os.BinderDeathDispatcher$RecipientsInfo
04-21 15:34:08.033 6929 6929 F DEBUG : 51196: 0x12d46130 com.android.internal.os.BinderDeathDispatcher$RecipientsInfo
04-21 15:34:08.033 6929 6929 F DEBUG : 51195: 0x12c98cf8 com.android.internal.os.BinderDeathDispatcher$RecipientsInfo
04-21 15:34:08.033 6929 6929 F DEBUG : 51194: 0x12d44350 com.android.server.power.PowerManagerService$WakeLock
04-21 15:34:08.033 6929 6929 F DEBUG : 51193: 0x12d0a020 com.android.server.power.PowerManagerService$WakeLock
04-21 15:34:08.033 6929 6929 F DEBUG : 51192: 0x12d06a80 com.android.server.am.PendingIntentRecord
04-21 15:34:08.033 6929 6929 F DEBUG : 51191: 0x14812ff8 com.android.server.job.JobServiceContext$JobCallback
04-21 15:34:08.033 6929 6929 F DEBUG : 51190: 0x1481da80 com.android.server.am.PendingIntentRecord
04-21 15:34:08.033 6929 6929 F DEBUG : Summary:
04-21 15:34:08.033 6929 6929 F DEBUG : 48898 of com.android.internal.os.BinderDeathDispatcher$RecipientsInfo (48898 unique instances)
04-21 15:34:08.033 6929 6929 F DEBUG : 404 of java.lang.Class (304 unique instances)
04-21 15:34:08.033 6929 6929 F DEBUG : 384 of java.nio.DirectByteBuffer (384 unique instances)
一.分析:
com.android.internal.os.BinderDeathDispatcher$RecipientsInfo 实例非常多,多大48898个,而总数才51200个,占比高达97%,所以需要从BinderDeathDispatcher$RecipientsInfo 这个多实例作为入口点。
1. 查看BinderDeathDispatcher$RecipientsInfo 源码,发现new BinderDeathDispatcher$RecipientsInfo 的地方只有一处:
frameworks/base/core/java/com/android/internal/os/BinderDeathDispatcher.java
/**
* Add a {@code recipient} to the death recipient list on {@code target}.
*
* @return # of recipients in the recipient list, including {@code recipient}. Or, -1
* if {@code target} is already dead, in which case recipient's
* {@link DeathRecipient#binderDied} won't be called.
*/
public int linkToDeath(@NonNull T target, @NonNull DeathRecipient recipient) {
final IBinder ib = target.asBinder();
synchronized (mLock) {
RecipientsInfo info = mTargets.get(ib);
if (info == null) {
info = new RecipientsInfo(ib);
// First recipient; need to link to death.
try {
ib.linkToDeath(info, 0);
} catch (RemoteException e) {
return -1; // Already dead.
}
mTargets.put(ib, info);
}
info.mRecipients.add(recipient);
return info.mRecipients.size();
}
}
public void unlinkToDeath(@NonNull T target, @NonNull DeathRecipient recipient) {
final IBinder ib = target.asBinder();
synchronized (mLock) {
final RecipientsInfo info = mTargets.get(ib);
if (info == null) {
return;
}
if (info.mRecipients.remove(recipient) && info.mRecipients.size() == 0) {
info.mTarget.unlinkToDeath(info, 0);
mTargets.remove(info.mTarget);
}
}
}
从代码中可以看出来,只有linkToDeath()方法,才会new RecipientsInfo,并将生成的对象,放置在mTargets 集合中。而unlinkToDeath 方法则将在mTargets 集合中移除此info。可以推断出,linkToDeath 调用太频繁。而linkToDeath 调用太频繁和谁有关?
2. 会发现,linkToDeath的记录是存在mTargets中,而mTargets里面个数是可以dump的。
查看代码:
frameworks/base/core/java/com/android/internal/os/BinderDeathDispatcher.java
/** Dump stats useful for debugging. Can be used from dump() methods of client services. */
public void dump(IndentingPrintWriter pw) {
synchronized (mLock) {
pw.print("# of watched binders: ");
pw.println(mTargets.size());
pw.print("# of death recipients: ");
int n = 0;
for (RecipientsInfo info : mTargets.values()) {
n += info.mRecipients.size();
}
pw.println(n);
}
}
3. 在bugreport中查看dump 信息:
发现watched binders: 42849,death recipients: 43130, pid 6200: 42321 observers。
pid 6200: 42321 observers
pid 2253: 345 observers
pid 2523: 107 observers
pid 3460: 84 observers
pid 3224: 55 observers
pid 4323: 38 observers
pid 5559: 31 observers
pid 2894: 28 observers
pid 4244: 16 observers
pid 29704: 10 observers
pid 2989: 7 observers
pid 3598: 7 observers
pid 3927: 7 observers
pid 2508: 6 observers
pid 5686: 6 observers
pid 7395: 5 observers
pid 7508: 5 observers
pid 2659: 4 observers
pid 3952: 4 observers
pid 4103: 4 observers
pid 4487: 4 observers
pid 2980: 3 observers
pid 6481: 3 observers
pid 6573: 3 observers
pid 12959: 3 observers
pid 2809: 2 observers
pid 2938: 2 observers
pid 2956: 2 observers
pid 3910: 2 observers
pid 3973: 2 observers
pid 5644: 2 observers
pid 6091: 2 observers
pid 24437: 2 observers
pid 2726: 1 observers
pid 4438: 1 observers
pid 4845: 1 observers
pid 5336: 1 observers
pid 5676: 1 observers
pid 5697: 1 observers
pid 6548: 1 observers
pid 10717: 1 observersTotal number of nodes: 572
Total number of observers: 43130
# of watched binders: 42849
# of death recipients: 43130
4. 从dump 信息可以看到pid 6200 有42321 observers,而总共的watched binders 有42849个。
怀疑和pid 6200 有关,导致会产生这么多的binder
查看dump 对应的代码:
frameworks/base/services/core/java/com/android/server/content/ContentService.java
@Override
protected synchronized void dump(FileDescriptor fd, PrintWriter pw_, String[] args) {
if (!DumpUtils.checkDumpAndUsageStatsPermission(mContext, TAG, pw_)) return;
final IndentingPrintWriter pw = new IndentingPrintWriter(pw_, " ");
final boolean dumpAll = ArrayUtils.contains(args, "-a");
// This makes it so that future permission checks will be in the context of this
// process rather than the caller's process. We will restore this before returning.
final long identityToken = clearCallingIdentity();
try {
if (mSyncManager == null) {
pw.println("SyncManager not available yet");
} else {
mSyncManager.dump(fd, pw, dumpAll);
}
pw.println();
pw.println("Observer tree:");
synchronized (mRootNode) {
int[] counts = new int[2];
final SparseIntArray pidCounts = new SparseIntArray();
mRootNode.dumpLocked(fd, pw, args, "", " ", counts, pidCounts);
pw.println();
ArrayList<Integer> sorted = new ArrayList<Integer>();
for (int i=0; i<pidCounts.size(); i++) {
sorted.add(pidCounts.keyAt(i));
}
Collections.sort(sorted, new Comparator<Integer>() {
@Override
public int compare(Integer lhs, Integer rhs) {
int lc = pidCounts.get(lhs);
int rc = pidCounts.get(rhs);
if (lc < rc) {
return 1;
} else if (lc > rc) {
return -1;
}
return 0;
}
});
for (int i=0; i<sorted.size(); i++) {
int pid = sorted.get(i);
pw.print(" pid "); pw.print(pid); pw.print(": ");
pw.print(pidCounts.get(pid)); pw.println(" observers");
}
pw.println();
pw.increaseIndent();
pw.print("Total number of nodes: "); pw.println(counts[0]);
pw.print("Total number of observers: "); pw.println(counts[1]);
sObserverDeathDispatcher.dump(pw);
pw.decreaseIndent();
}
synchronized (sObserverLeakDetectedUid) {
pw.println();
pw.print("Observer leaking UIDs: ");
pw.println(sObserverLeakDetectedUid.toString());
}
synchronized (mCache) {
pw.println();
pw.println("Cached content:");
pw.increaseIndent();
for (int i = 0; i < mCache.size(); i++) {
pw.println("User " + mCache.keyAt(i) + ":");
pw.increaseIndent();
pw.println(mCache.valueAt(i));
pw.decreaseIndent();
}
pw.decreaseIndent();
}
} finally {
restoreCallingIdentity(identityToken);
}
}
从代码中发现,pid的统计来自 pidCounts 值,而pidCounts来自于mRootNode, 对应的代码是:mRootNode.dumpLocked(fd, pw, args, "", " ", counts, pidCounts); 然而,mRootNode 里面数据来自于mRootNode.addObserverLocked() 方法.
private void addObserverLocked(Uri uri, int index, IContentObserver observer,
boolean notifyForDescendants, Object observersLock,
int uid, int pid, int userHandle) {
// If this is the leaf node add the observer
if (index == countUriSegments(uri)) {
mObservers.add(new ObserverEntry(observer, notifyForDescendants, observersLock,
uid, pid, userHandle, uri));
return;
}
// Look to see if the proper child already exists
String segment = getUriSegment(uri, index);
if (segment == null) {
throw new IllegalArgumentException("Invalid Uri (" + uri + ") used for observer");
}
int N = mChildren.size();
for (int i = 0; i < N; i++) {
ObserverNode node = mChildren.get(i);
if (node.mName.equals(segment)) {
node.addObserverLocked(uri, index + 1, observer, notifyForDescendants,
observersLock, uid, pid, userHandle);
return;
}
}
// No child found, create one
ObserverNode node = new ObserverNode(segment);
mChildren.add(node);
node.addObserverLocked(uri, index + 1, observer, notifyForDescendants,
observersLock, uid, pid, userHandle);
}
可以看出来,每次调用addObserverLocked 方法都会累加,若是第一次调用没有ObserverNode,则新增加一个ObserverNode进行统计。
而外部调用addObserverLocked()方法的只有一处:
@Override
public void registerContentObserver(Uri uri, boolean notifyForDescendants,
IContentObserver observer, int userHandle, int targetSdkVersion) {
if (observer == null || uri == null) {
throw new IllegalArgumentException("You must pass a valid uri and observer");
}
final int uid = Binder.getCallingUid();
final int pid = Binder.getCallingPid();
userHandle = handleIncomingUser(uri, pid, uid,
Intent.FLAG_GRANT_READ_URI_PERMISSION, true, userHandle);
final String msg = LocalServices.getService(ActivityManagerInternal.class)
.checkContentProviderAccess(uri.getAuthority(), userHandle);
if (msg != null) {
if (targetSdkVersion >= Build.VERSION_CODES.O) {
throw new SecurityException(msg);
} else {
if (msg.startsWith("Failed to find provider")) {
// Sigh, we need to quietly let apps targeting older API
// levels notify on non-existent providers.
} else {
Log.w(TAG, "Ignoring content changes for " + uri + " from " + uid + ": " + msg);
return;
}
}
}
synchronized (mRootNode) {
mRootNode.addObserverLocked(uri, observer, notifyForDescendants, mRootNode,
uid, pid, userHandle);
if (false) Log.v(TAG, "Registered observer " + observer + " at " + uri +
" with notifyForDescendants " + notifyForDescendants);
}
}
也就说外部有应用大量调用registerContentObserver方法。
5.定位是谁大量调用了registerContentObserver。前面已经提到pid 6200: 42321 observers,从信息可以的出来,pid 6200 ,有42321次调用registerContentObserver方法,而没有调用unregisterContentObserver方法,造成内存泄露。
6.定位应用: 通过PID 很快定位是那个应用.
-> 6200:com.android.**/1000 s1/1 u0/0 +22h36m40s118m
可以看到是此应该就是 com.android.**.
7. 找到这个应用源码,搜索registerContentObserver 关键子。 果然发现了异常:
@Override
public void onReceive(Context context, Intent intent) {
...
context.getApplicationContext().getContentResolver().registerContentObserver(...);
context.getApplicationContext().getContentResolver().registerContentObserver(...);
context.getApplicationContext().getContentResolver().registerContentObserver(...);
context.getApplicationContext().getContentResolver().registerContentObserver(...);
context.getApplicationContext().getContentResolver().registerContentObserver(...);
在BroadcastReceiver 中onReceive方法里面写了6次registerContentObserver 调用。而且,还没有生命周期调用unRegisterContentObserver方法。 造成了内存泄露。
可以从log 中证实了这一点.
04-18 17:59:49.140 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 17:59:57.341 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:00:05.527 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:00:13.723 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:00:21.913 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:00:30.100 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:00:38.304 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:00:46.521 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:00:54.750 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:01:11.068 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:01:19.268 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:01:27.448 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:01:35.666 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:01:43.835 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:01:52.021 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:02:00.266 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:02:08.451 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:02:16.596 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:02:24.788 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:02:32.980 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:02:41.226 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:02:49.391 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:02:57.557 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:03:05.754 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:03:14.022 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:03:22.186 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:03:30.329 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:03:38.519 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:03:46.712 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:03:54.958 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:04:03.119 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:04:11.299 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:04:19.481 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:04:27.717 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:04:35.904 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:04:44.060 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:04:52.249 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:05:00.452 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:05:08.686 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:05:16.845 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:05:25.045 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:05:33.213 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:05:41.405 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:05:49.635 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:05:57.780 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:06:05.978 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:06:14.169 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:06:22.423 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:06:30.553 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:06:38.743 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:06:46.941 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:06:55.129 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:07:03.383 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:07:11.574 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
04-18 18:07:19.766 19325 19325 D USBPowerSaving: StateReceiver onReceive = com.android.action.USB_CHARGING_STATE
Broadcast 发送特别频繁,导致registerContentObserver 调用次数特别多。
二. 总结:
1. 写代码时一定要注意内存泄露的问题,阅读代码规范。内存泄露问题很难察觉,这次能发现,是因为特定情况下,量变到质变手机发生了重启,抓到了dump 信息。若内存泄露没有达到此极限是无法察觉的。
2.发现有类似的问题,一定要根据源码分析,要利用源码中的dump方法,必要时,在里面添加自己需要监听的变量值打印。