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