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內存泄漏分析及調試