Android Memory/Resource Leak总结

Android的内存/资源泄露，不容易发现，又会引发app甚至是system的一系列问题。

在这里我根据以往碰到的相关问题，总结出了一些检测和修改方法。

*有可能造成memory leak的代码是Framework层的文件，但最终影响了App层的进程；
 所以发现app进程出现memory leak的时候，也要考虑Framework层是否有问题。
*确保一定close资源：try { return; } finally { resource.close(); } 这样即使try块中有return语句，也能保证finally块中的close被执行到。
*resource leak的检查需要启动StrictMode。

1.文件IO没有关闭

现象：对app进行重复“进入-退出”的自动化测试，500+次之后出现ANR。

E/StrictMode(  618): A resource was acquired at attached stack trace but never released. 
                     See java.io.Closeable for information on avoiding resource leaks.
E/StrictMode(  618): java.lang.Throwable: Explicit termination method 'close' not called
E/StrictMode(  618):     at dalvik.system.CloseGuard.open(CloseGuard.java:184)
E/StrictMode(  618):     at java.io.FileInputStream.<init>(FileInputStream.java:80)
E/StrictMode(  618):     at java.io.FileReader.<init>(FileReader.java:42)
E/StrictMode(  618):     at android.net.http.AndroidHttpClient.fun3(AndroidHttpClient.java:) <- 出错位置
E/StrictMode(  618):     at android.net.http.AndroidHttpClient.fun2(AndroidHttpClient.java:)
E/StrictMode(  618):     at android.net.http.AndroidHttpClient.fun1(AndroidHttpClient.java:)
E/StrictMode(  618):     at com.android.server.location.GpsXtraDownloader.doDownload(GpsXtraDownloader.java:143)
E/StrictMode(  618):     at com.android.server.location.GpsXtraDownloader.downloadXtraData(GpsXtraDownloader.java:100)
E/StrictMode(  618):     at com.android.server.location.GpsLocationProvider$6.run(GpsLocationProvider.java:1023)
E/StrictMode(  618):     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
E/StrictMode(  618):     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
E/StrictMode(  618):     at java.lang.Thread.run(Thread.java:841)

这种错误不会被容易察觉，但可以避免或在前期找出错误。
小结：
a.不再使用的文件IO要调用close()释放；
b.搜索Log中是否有"release", "leak", "java.io.Closeable"等关键词；
c.BufferedReader br = new BufferedReader(new FileReader(file)); close掉BufferedReader也会隐式close掉FileReader；
d.可能有频繁GC，造成屏幕画面卡顿（如Rotation）：

12-06 13:44:13.970  9552  9556 E dalvikvm: 9552(com.test.app) stat: (e) 63 937KB / (c) 11 31MB / (a) 4 13MB / (h) 15MB 20MB 4485KB
12-06 13:44:13.970  9552  9556 D dalvikvm: GC_CONCURRENT freed 8183K, 32% free 23967K/34952K, paused 4ms+25ms, total 150ms
12-06 13:44:13.970  9552  9652 D dalvikvm: WAIT_FOR_CONCURRENT_GC blocked 156ms
12-06 13:44:13.970  9552  9654 D dalvikvm: WAIT_FOR_CONCURRENT_GC blocked 155ms
12-06 13:44:13.970  9552  9658 D dalvikvm: WAIT_FOR_CONCURRENT_GC blocked 156ms
12-06 13:44:13.970  9552  9656 D dalvikvm: WAIT_FOR_CONCURRENT_GC blocked 156ms
12-06 13:44:13.975  9552  9660 D dalvikvm: WAIT_FOR_CONCURRENT_GC blocked 157ms
12-06 13:44:13.980  9552  9561 E StrictMode: A resource was acquired at attached stack trace but never released. 
                                             See java.io.Closeable for information on avoiding resource leaks.
12-06 13:44:13.980  9552  9561 E StrictMode: java.lang.Throwable: Explicit termination method 'close' not called
12-06 13:44:13.980  9552  9561 E StrictMode:     at dalvik.system.CloseGuard.open(CloseGuard.java:184)
12-06 13:44:13.980  9552  9561 E StrictMode:     at java.io.FileInputStream.<init>(FileInputStream.java:80)
12-06 13:44:13.980  9552  9561 E StrictMode:     at com.test.app.*(Unknown Source) 

2.Cursor没有关闭

现象：自动化测试800+次以后手机reboot

E/StrictMode( 3814): Finalizing a Cursor that has not been deactivated or closed. 
        　　　　　　   database = /data/data/com.test.app/databases/..., table = null, query = SELECT * FROM table WHERE package = '';
E/StrictMode( 3814): android.database.sqlite.DatabaseObjectNotClosedException: 
        　　　　　　   Application did not close the cursor or database object that was opened here
E/StrictMode( 3814):     at android.database.sqlite.SQLiteCursor.<init>(SQLiteCursor.java:98)
E/StrictMode( 3814):     at android.database.sqlite.SQLiteDirectCursorDriver.query(SQLiteDirectCursorDriver.java:50)
E/StrictMode( 3814):     at android.database.sqlite.SQLiteDatabase.rawQueryWithFactory(SQLiteDatabase.java:1436)
E/StrictMode( 3814):     at android.database.sqlite.SQLiteDatabase.rawQuery(SQLiteDatabase.java:1375)
E/StrictMode( 3814):     at com.test.app.*(Unknown Source)

小结：
a.过多cursor会造成Excessive JNI global references，导致system_server的VM aborting
b.Log关键词："DatabaseObjectNotClosedException"

3. InputChannel fd过多

现象：压力测试反复打开关闭某App 200~300次后出现FC

03-07 15:37:56.334 E/AndroidRuntime( 5338): FATAL EXCEPTION: main
03-07 15:37:56.334 E/AndroidRuntime( 5338): Process: com.app.foo, PID: 5338
03-07 15:37:56.334 E/AndroidRuntime( 5338): java.lang.RuntimeException: Could not read input channel file descriptors from parcel.
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.view.InputChannel.nativeReadFromParcel(Native Method)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.view.InputChannel.readFromParcel(InputChannel.java:148)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.view.IWindowSession$Stub$Proxy.addToDisplay(IWindowSession.java:717)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.view.ViewRootImpl.setView(ViewRootImpl.java:727)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.view.WindowManagerGlobal.addView(WindowManagerGlobal.java:278)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.view.WindowManagerImpl.addView(WindowManagerImpl.java:69)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.app.ActivityThread.handleResumeActivity(ActivityThread.java:3061)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2391)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.app.ActivityThread.access$900(ActivityThread.java:169)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1277)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.os.Handler.dispatchMessage(Handler.java:102)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.os.Looper.loop(Looper.java:136)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at android.app.ActivityThread.main(ActivityThread.java:5476)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at java.lang.reflect.Method.invokeNative(Native Method)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at java.lang.reflect.Method.invoke(Method.java:515)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1268)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1084)
03-07 15:37:56.334 E/AndroidRuntime( 5338): at dalvik.system.NativeStart.main(Native Method)

分析：
App的input event由WindowManagerService管理，WMS会内部创建一个InputManager，两者的连接通过InputChannel来完成。
WMS需要注册两个InputChannel与InputManager连接，其中Server端InputChannel注册在InputManager（SystemServer进程）当中，Client端注册在应用程序主线程中。

InputChannel使用Ashmem匿名共享内存来传递数据，它由一个fd文件描述符指向，同时read端和write端各占用一个fd。
当我们打开一个app时，设置log的tag为"InputTransport"，可以看到server(system_server)和client(app)都会construct fd。

809 InputTransport Input channel constructed: name='426d6588 com.app.phone/com.app.phone.ActivityWelcome (server)', fd=431
19501 InputTransport Input channel constructed: name='426d6588 com.app.phone/com.app.phone.ActivityWelcome (client)', fd=58

实际案例：

当startActivity的intent flag被设置为Intent.FLAG_ACTIVITY_MULTIPLE_TASK类似flag的时候，如果没有处理好Activity的生命周期，
就会造成Activity无法回收（RecentApps中大量的task），而所占用的fd指向的ashmem也无法释放（errno = 24），就会造成上述问题。

4. so库内存泄漏

现象：反复打开/关闭某个系统服务（跨层），高概率出现system server挂掉重启

01-19 09:34:47.454  2997  2997 F libc    : Fatal signal 11 (SIGSEGV), code 1, fault addr 0x9e2ec3aa in tid 2997 (system_server)
01-19 09:34:47.579  2337  2337 I DEBUG   : Revision: '11'
01-19 09:34:47.579  2337  2337 I DEBUG   : ABI: 'arm'
01-19 09:34:47.579  2337  2337 I DEBUG   : pid: 2997, tid: 2997, name: system_server  >>> system_server <<<
01-19 09:34:47.579  2337  2337 I DEBUG   : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x9e2ec3aa
01-19 09:34:47.609  2337  2337 I DEBUG   :     r0 be9ceb48  r1 0000000c  r2 0000011d  r3 00008600
01-19 09:34:47.609  2337  2337 I DEBUG   :     r4 00000000  r5 00000000  r6 be9ceb48  r7 00000000
01-19 09:34:47.609  2337  2337 I DEBUG   :     r8 be9ceb48  r9 9e2ec3aa  sl 0000011d  fp 6f11d000
01-19 09:34:47.609  2337  2337 I DEBUG   :     ip 0000000c  sp be9ceac0  lr b6bedbdd  pc b6b8e1b0  cpsr 20000010
01-19 09:34:47.609  2337  2337 I DEBUG   : 
01-19 09:34:47.609  2337  2337 I DEBUG   : backtrace:
01-19 09:34:47.609  2337  2337 I DEBUG   :     #00 pc 0000b1b0  /system/lib/libz.so (inflate+856)
01-19 09:34:47.609  2337  2337 I DEBUG   :     #01 pc 0001bbd9  /system/lib/libandroidfw.so (bool inflateToBuffer<BufferReader>(BufferReader&, void*, long, long)+164)
01-19 09:34:47.609  2337  2337 I DEBUG   :     #02 pc 0001bc5b  /system/lib/libandroidfw.so (android::ZipUtils::inflateToBuffer(void*, void*, long, long)+14)
01-19 09:34:47.609  2337  2337 I DEBUG   :     #03 pc 0000f887  /system/lib/libandroidfw.so (android::_CompressedAsset::getBuffer(bool)+50)
01-19 09:34:47.609  2337  2337 I DEBUG   :     #04 pc 0008b313  /system/lib/libandroid_runtime.so
01-19 09:34:47.609  2337  2337 I DEBUG   :     #05 pc 007e9abf  /system/framework/arm/boot.oat

分析：
从打印出来的backtrace可以看出，问题发生在framework层调用native层so库，进行inflate app的XML文件的时候出错。
由于出错地方是在Android原生代码（无二次修改）中，并且增加打印log后发现每次出错时XML文件可能来自不同app，所以可以怀疑是其他地方的错误导致的。

我们知道，进程对压缩的XML进行解压、inflate时需要较大的内存空间。这时候遇到的Segment Fault很可能是由于其他地方的memory leak造成的。
而memory leak的地方，就是在system server自身当中或者是它调用过的so库（so库使用的内存也属于调用进程的）。
经过了长时间的分析和排查代码，最后果真在某个库中发现了申请内存和释放内存存在隐患的代码。修改后问题解决。

从这个debug分析的过程，我们可以得到以下经验:

1. 由于C/C++不带有GC，一开始写关于内存申请释放的代码的时候就要细心，否则出问题（涉及到如system server的问题很严重）要耗费大量的人力时间去debug；
2. backtrace只能说明执行到哪里出错了，不能说明出错的根本原因是什么；
3. 分析问题log，还是可以有根据地提出假设再验证（比如看到inflate就假设memory leak）。

 

相关文章

Android内存泄漏研究

Android内存泄漏分析及调试