前言
前段时间遇到了一个死机重启问题,比较复杂,涉及到多方面的知识,我也分析了很长的时间,期间学到了很多东西,现在把分析的过程整理一下,希望可以给大家一点帮助和启发,同时也帮助自己再巩固一下。
一、问题的复现
首先说一下问题最开始的分析思路以及复现的过程,log 中最核心的部分如下所示:
10-17 12:13:02.004 2096 4139 W art : Large object allocation failed: ashmem_create_region failed for 'large object space allocation': Too many open files
10-17 12:13:02.004 2096 4139 I art : Starting a blocking GC Alloc
10-17 12:13:02.004 2096 4139 I art : Starting a blocking GC Alloc
10-17 12:13:02.005 22944 28199 D MscSpeechLog: QTTSAudioGet enter
10-17 12:13:02.005 22944 28199 D MSC_LOG : QTTSAudioGet Begin
10-17 12:13:02.006 22944 28199 D MSC_LOG : QTTSAudioGet End
10-17 12:13:02.006 2096 2096 D AndroidRuntime: Shutting down VM
10-17 12:13:02.006 22944 28199 D MscSpeechLog: QTTSAudioGet leavel:0value len = 0
10-17 12:13:02.006 2096 5712 E JavaBinder: *** Uncaught remote exception! (Exceptions are not yet supported across processes.)
10-17 12:13:02.006 2096 5712 E JavaBinder: java.lang.RuntimeException: Could not copy bitmap to parcel blob.
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.graphics.Bitmap.nativeWriteToParcel(Native Method)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.graphics.Bitmap.writeToParcel(Bitmap.java:1553)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.widget.RemoteViews$BitmapCache.writeBitmapsToParcel(RemoteViews.java:984)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.widget.RemoteViews.writeToParcel(RemoteViews.java:2854)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.app.Notification.writeToParcel(Notification.java:1687)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.service.notification.StatusBarNotification.writeToParcel(StatusBarNotification.java:124)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.service.notification.IStatusBarNotificationHolder$Stub.onTransact(IStatusBarNotificationHolder.java:53)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.os.Binder.execTransact(Binder.java:453)
10-17 12:13:02.007 3362 15429 W Binder : Caught a RuntimeException from the binder stub implementation.
10-17 12:13:02.007 3362 15429 W Binder : java.lang.NullPointerException: Attempt to invoke virtual method 'android.app.Notification android.service.notification.StatusBarNotification.getNotification()' on a null object reference
10-17 12:13:02.007 3362 15429 W Binder : at android.service.notification.NotificationListenerService$INotificationListenerWrapper.onNotificationPosted(NotificationListenerService.java:692)
10-17 12:13:02.007 3362 15429 W Binder : at android.service.notification.INotificationListener$Stub.onTransact(INotificationListener.java:71)
10-17 12:13:02.007 3362 15429 W Binder : at android.os.Binder.execTransact(Binder.java:453)
--------- beginning of crash
10-17 12:13:02.007 2096 2096 E AndroidRuntime: *** FATAL EXCEPTION IN SYSTEM PROCESS: main
10-17 12:13:02.007 2096 2096 E AndroidRuntime: java.lang.RuntimeException: Could not copy bitmap to parcel blob.
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.graphics.Bitmap.nativeWriteToParcel(Native Method)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.graphics.Bitmap.writeToParcel(Bitmap.java:1553)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.widget.RemoteViews$BitmapCache.writeBitmapsToParcel(RemoteViews.java:984)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.widget.RemoteViews.writeToParcel(RemoteViews.java:2854)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.widget.RemoteViews.clone(RemoteViews.java:1903)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.app.Notification.cloneInto(Notification.java:1521)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.app.Notification.clone(Notification.java:1495)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.service.notification.StatusBarNotification.clone(StatusBarNotification.java:161)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at com.android.server.notification.NotificationManagerService$NotificationListeners.notifyPostedLocked(NotificationManagerService.java:3398)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at com.android.server.notification.NotificationManagerService$8.run(NotificationManagerService.java:2228)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.os.Handler.handleCallback(Handler.java:742)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.os.Handler.dispatchMessage(Handler.java:95)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at android.os.Looper.loop(Looper.java:157)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at com.android.server.SystemServer.run(SystemServer.java:302)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at com.android.server.SystemServer.main(SystemServer.java:176)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at java.lang.reflect.Method.invoke(Native Method)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:746)
10-17 12:13:02.007 2096 2096 E AndroidRuntime: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:636)
最开始的思路是觉得发生了 fd 泄露,进程中存在很多打开的 fd,从而导致 copy bitmap to parcel blob 失败。另外,发生问题前有大量 10-17 12:12:07.101 3362 3362 D PhoneStatusBar: updateNotification pkg=com.ophone.reader.ui;id=1 log 打出,大约三百多次。因此认为是频繁 updateNotification 导致了 fd 的泄露,下面就是尝试复现一下来验证自己的这个想法。
首先,研究了一下 updateNotification 这种 log 是如何打出的,根据系统 notification 的机制,app 创建一个 notification,然后调用 NotificationManager 的 public void notify(int id, Notification notification) 方法,假如之前 notify 过同一 id,那么再次 notify 此 id 时就会有这样的 log 打出(忽略一些细节条件判断)。于是写了一个 demo,每次改变 notification 的 TextViewText,并且循环 notify。然而问题并没有复现。
再次观察 log 查看是否有遗漏的细节,发现几份 log 中都是 pkg=com.ophone.reader.ui;id=1,由此可见这个 app 的 notification 这里一定有什么过人之处。。。于是下载这个 app(咪咕阅读)查看其 notification 是什么样子的。然而……,我并不知道这个 notification 是怎么出现的,只得作罢。
再次观察 log 发现同样每份 log 中有大量
10-17 12:12:07.083 22944 28033 D MscSpeechLog: QTTSAudioGet enter
10-17 12:12:07.083 22944 28033 D MSC_LOG : QTTSAudioGet Begin
10-17 12:12:07.084 22944 28033 D MSC_LOG : QTTSAudioGet End
10-17 12:12:07.084 22944 28033 D MscSpeechLog: QTTSAudioGet leavel:0value len = 0
10-17 12:12:07.094 22944 28033 D MscSpeechLog: QTTSAudioGet enter
10-17 12:12:07.094 22944 28033 D MSC_LOG : QTTSAudioGet Begin
10-17 12:12:07.094 22944 28033 D MSC_LOG : QTTSAudioGet End
10-17 12:12:07.094 22944 28033 D MscSpeechLog: QTTSAudioGet leavel:0value len = 0
这种 log 打出,甚至怀疑 fd 泄露是不是跟这些 log 有关?再次看这些 log 发现这些 log 好像是某种文字转语音引擎打出的,于是恍然大悟,打开咪咕阅读,随便找一本小说,开启语音朗读,回到桌面,下拉通知栏,果然发现了咪咕阅读的 notification。可是,notification 的内容并没有更新啊,为什么会频繁打出 updateNotification 这样的 log 呢。仔细盯了通知一分钟,发现这个 notification 每隔不到 10 秒,停止按钮的图标就会由 II 样子变为三角然后再变回来(不知道其目的是什么,我总感觉是循环的逻辑出了问题)。于是我也仿照它的样子,写了一个 remoteView 里面设置了一个 bitmap,并把 remoteView 添加到 notification 中,频繁切换 bitmap 并且 notify notification,问题果然复现。
二、这样的 log 产生的原因
下面我们看一下为什么会打出这样的 log,首先分析一下:
10-17 12:13:02.006 2096 5712 E JavaBinder: *** Uncaught remote exception! (Exceptions are not yet supported across processes.)
10-17 12:13:02.006 2096 5712 E JavaBinder: java.lang.RuntimeException: Could not copy bitmap to parcel blob.
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.graphics.Bitmap.nativeWriteToParcel(Native Method)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.graphics.Bitmap.writeToParcel(Bitmap.java:1553)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.widget.RemoteViews$BitmapCache.writeBitmapsToParcel(RemoteViews.java:984)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.widget.RemoteViews.writeToParcel(RemoteViews.java:2854)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.app.Notification.writeToParcel(Notification.java:1687)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.service.notification.StatusBarNotification.writeToParcel(StatusBarNotification.java:124)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.service.notification.IStatusBarNotificationHolder$Stub.onTransact(IStatusBarNotificationHolder.java:53)
10-17 12:13:02.006 2096 5712 E JavaBinder: at android.os.Binder.execTransact(Binder.java:453)
10-17 12:13:02.007 3362 15429 W Binder : Caught a RuntimeException from the binder stub implementation.
10-17 12:13:02.007 3362 15429 W Binder : java.lang.NullPointerException: Attempt to invoke virtual method 'android.app.Notification android.service.notification.StatusBarNotification.getNotification()' on a null object reference
10-17 12:13:02.007 3362 15429 W Binder : at android.service.notification.NotificationListenerService$INotificationListenerWrapper.onNotificationPosted(NotificationListenerService.java:692)
10-17 12:13:02.007 3362 15429 W Binder : at android.service.notification.INotificationListener$Stub.onTransact(INotificationListener.java:71)
10-17 12:13:02.007 3362 15429 W Binder : at android.os.Binder.execTransact(Binder.java:453)
这段 log 产生的原因。首先我们思考一下这样几个问题:
- 1、2096 3362 分别是哪两个进程?
- 2、null object 是怎么来的?
2.1 三个进程
这段 log 是在 app 更新或者添加 notification 的过程中产生的,所以我们先看一下更新或添加 notification 的调用流程:
- 不同的颜色代表不同的进程,红色运行在 app 进程,黑色在 system_server 进程,蓝色在 systemui (也可能是其他注册过的进程)进程
- 其中涉及到三次跨进程调用,依次为:app 进程调用 system_server 进程的
enqueueNotificationWithTag
方法、system_server 进程调用 systemui 进程的onNotificationPosted
方法、systemui 进程调用 system_server 进程的get
方法
第一次跨进程调用很常见,我们就不做讨论了,主要看一下第二、三次跨进程调用是如何实现的。首先,我们需要了解一下 NotificationListener 的注册流程(以 systemui 为例),如下图所示:
- 其中红色部分运行在 systemui 进程,蓝色部分运行在 system_server 进程
- StatusBar 的成员 mNotificationListener 是一个 NotificationListenerService 实例,其会调用 registerAsSystemService 方法来进行注册
下面我们来看一下 registerAsSystemService 的实现:
NotificationListenerService.java
public void registerAsSystemService(Context context, ComponentName componentName,
int currentUser) throws RemoteException {
mSystemContext = context;
if (mWrapper == null) {
mWrapper = new INotificationListenerWrapper();
}
INotificationManager noMan = getNotificationInterface();
noMan.registerListener(mWrapper, componentName, currentUser);
mCurrentUser = currentUser;
}
- 通过 getNotificationInterface 方法得到 NMS (NotificationManagerService) 的代理,NMS 是在 ServiceManager 中注册过的
- 如果 mWrapper == null,那么创建一个 INotificationListenerWrapper 对象(INotificationListenerWrapper extends INotificationListener.Stub)赋给它
- 将 mWrapper 作为参数(其写入 parcel 时会调用 writeStrongBinder 方法,将其 IBinder 对象写入),调用 NMS 的 registerListener 方法,由此看来 mWrapper 提供了一个匿名 Binder 服务
(匿名 Binder 服务机制,本文不详细展开)
下面我们来看一下 registerService 的实现:
ManagedServices.java
public void registerService(IInterface service, ComponentName component, int userid) {
checkNotNull(service);
ManagedServiceInfo info = registerServiceImpl(service, component, userid);
if (info != null) {
onServiceAdded(info);
}
}
可以看到其分为两部分,我们主要看一下 registerServiceImpl 部分:
ManagedServices.java
private ManagedServiceInfo registerServiceImpl(final IInterface service,
final ComponentName component, final int userid) {
synchronized (mMutex) {
try {
// 这里的 service 实际上可以看作之前 mWrapper 的代理
ManagedServiceInfo info = newServiceInfo(service, component, userid,
true /*isSystem*/, null, Build.VERSION_CODES.LOLLIPOP);
service.asBinder().linkToDeath(info, 0);
mServices.add(info);
return info;
} catch (RemoteException e) {
// already dead
}
}
return null;
}
- 将 service 以及 component 等数据包装成一个 ManagedServiceInfo 对象
- 将包装好的这个对象添加到 mServices 中
mServices 会在 notify notification 流程的 notifyPostedLocked 方法中用到:
NotificationManagerService.java
public void notifyPostedLocked(StatusBarNotification sbn, StatusBarNotification oldSbn) {
......
for (final ManagedServiceInfo info : mServices) {
......
mHandler.post(new Runnable() {
@Override
public void run() {
notifyPosted(info, sbnToPost, update);
}
});
}
}
从中可以看出此方法是从 mServices 中取出之前添加的 ManagedServiceInfo 对象,然后执行 notifyPosted(info, sbnToPost, update) 方法,看一下 notifyPosted 的实现:
NotificationManagerService.java
private void notifyPosted(final ManagedServiceInfo info,
final StatusBarNotification sbn, NotificationRankingUpdate rankingUpdate) {
final INotificationListener listener = (INotificationListener)info.service;
StatusBarNotificationHolder sbnHolder = new StatusBarNotificationHolder(sbn);
try {
listener.onNotificationPosted(sbnHolder, rankingUpdate);
} catch (RemoteException ex) {
Log.e(TAG, "unable to notify listener (posted): " + listener, ex);
}
}
info.service 就是包装之前的 service,因此 listener 即为之前 mWrapper 的代理,通过 listener.onNotificationPosted(sbnHolder, rankingUpdate) 也就实现了这次跨进程调用,由 system_server 进程进入了 systemui 进程。
我们看一下 StatusBarNotificationHolder 这个类:
NotificationManagerService.java
private static final class StatusBarNotificationHolder
extends