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)。
相关文章