trace檔案分析ANR問題
阿新 • • 發佈：2019-02-08
開啟dropbox中對應的system_app_anrxxxx: 檢視主執行緒的棧： "main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 obj=0x752b0000 self=0xb4276500 | sysTid=25390 nice=-1 cgrp=default sched=3/0 handle=0xb6f18b34 | state=S schedstat=( 0 0 0 ) utm=81 stm=12 core=2 HZ=100 | stack=0xbe78b000-0xbe78d000 stackSize=8MB | held mutexes= kernel: (couldn't read /proc/self/task/25390/stack) native: #00 pc 000422d0 /system/lib/libc.so (__ioctl+8) native: #01 pc 00047825 /system/lib/libc.so (ioctl+14) native: #02 pc 0001e835 /system/lib/libbinder.so (_ZN7android14IPCThreadState14talkWithDriverEb+132) native: #03 pc 0001ee93 /system/lib/libbinder.so (_ZN7android14IPCThreadState15waitForResponseEPNS_6ParcelEPi+38) native: #04 pc 0001f049 /system/lib/libbinder.so (_ZN7android14IPCThreadState8transactEijRKNS_6ParcelEPS1_j+124) native: #05 pc 00019fe3 /system/lib/libbinder.so (_ZN7android8BpBinder8transactEjRKNS_6ParcelEPS1_j+30) native: #06 pc 0008a035 /system/lib/libandroid_runtime.so (???) native: #07 pc 00d78869 /data/dalvik-cache/arm/[email protected]@boot.oat (Java_android_os_BinderProxy_transactNative__ILandroid_os_Parcel_2Landroid_os_Parcel_2I+140) at android.os.BinderProxy.transactNative(Native method) at android.os.BinderProxy.transact(Binder.java:510) at android.os.storage.IMountService$Stub$Proxy.getVolumeList(IMountService.java:771) at android.os.storage.StorageManager.getVolumeList(StorageManager.java:883) at android.os.Environment$UserEnvironment.getExternalDirs(Environment.java:95) at android.os.Environment.getExternalStorageDirectory(Environment.java:354) at com.huawei.common.utils.PathUtils.<clinit>(PathUtils.java:51) at com.huawei.common.utils.PathUtils.getWorkspacePath(PathUtils.java:80) at com.huawei.common.components.log.Logger.<clinit>(Logger.java:37) at com.huawei.common.components.log.Logger.i(Logger.java:162) at com.huawei.hwvplayer.data.db.DbProvider.attachInfo(DbProvider.java:89) at android.app.ActivityThread.installProvider(ActivityThread.java:5279) at android.app.ActivityThread.installContentProviders(ActivityThread.java:4868) at android.app.ActivityThread.handleBindApplication(ActivityThread.java:4799) at android.app.ActivityThread.access$1600(ActivityThread.java:165) at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1436) at android.os.Handler.dispatchMessage(Handler.java:102) at android.os.Looper.loop(Looper.java:188) at android.app.ActivityThread.main(ActivityThread.java:5578) at java.lang.reflect.Method.invoke!(Native method) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:794) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:684) 主執行緒嘗試去呼叫MountService的 getVolumeList介面，可能沒有返回。 檢視system_server中相關的，搜尋getVolumeList 發現systemserver中有三個Binder執行緒和主執行緒被block，我們的對端是哪個Binder執行緒暫時無法確認，但這並不影響我們繼續分析，因為他們被blockd的路徑是一致的： "main" prio=5 tid=1 Blocked | group="main" sCount=1 dsCount=0 obj=0x752b0000 self=0xb4276500 | sysTid=22735 nice=-2 cgrp=default sched=0/0 handle=0xb6f18b34 | state=S schedstat=( 0 0 0 ) utm=432 stm=85 core=1 HZ=100 | stack=0xbe78b000-0xbe78d000 stackSize=8MB | held mutexes= at com.android.server.MountService.getVolumeList(MountService.java:2759) - waiting to lock <0x0eeb54f1> (a java.lang.Object) held by thread 40 at android.os.storage.StorageManager.getVolumeList(StorageManager.java:883) at android.os.storage.StorageManager.getVolumeList(StorageManager.java:858) at android.os.storage.StorageManager.getPrimaryVolume(StorageManager.java:906) at com.android.server.usb.UsbDeviceManager.systemReady(UsbDeviceManager.java:327) at com.android.server.usb.UsbService.systemReady(UsbService.java:181) at com.android.server.usb.UsbService$Lifecycle.onBootPhase(UsbService.java:78) at com.android.server.SystemServiceManager.startBootPhase(SystemServiceManager.java:135) at com.android.server.SystemServer$3.run(SystemServer.java:1489) at com.android.server.am.ActivityManagerService.systemReady(ActivityManagerService.java:12417) at com.android.server.am.HwActivityManagerService.systemReady(HwActivityManagerService.java:960) at com.android.server.SystemServer.startOtherServices(SystemServer.java:1485) at com.android.server.SystemServer.run(SystemServer.java:381) at com.android.server.SystemServer.main(SystemServer.java:272) at java.lang.reflect.Method.invoke!(Native method) at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:794) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:684) "Binder_8" prio=5 tid=76 Blocked | group="main" sCount=1 dsCount=0 obj=0x13bd60a0 self=0x9c1abe00 | sysTid=25191 nice=-1 cgrp=default sched=0/0 handle=0x97158930 | state=S schedstat=( 0 0 0 ) utm=9 stm=7 core=2 HZ=100 | stack=0x9705c000-0x9705e000 stackSize=1014KB | held mutexes= at com.android.server.MountService.getVolumeList(MountService.java:2759) - waiting to lock <0x0eeb54f1> (a java.lang.Object) held by thread 40 at android.os.storage.IMountService$Stub.onTransact(IMountService.java:1634) at android.os.Binder.execTransact(Binder.java:453) "Binder_2" prio=5 tid=8 Blocked | group="main" sCount=1 dsCount=0 obj=0x12cac0a0 self=0xaebf0300 | sysTid=22761 nice=-1 cgrp=default sched=0/0 handle=0xaef7d930 | state=S schedstat=( 0 0 0 ) utm=41 stm=25 core=0 HZ=100 | stack=0xaee81000-0xaee83000 stackSize=1014KB | held mutexes= at com.android.server.MountService.getVolumeList(MountService.java:2759) - waiting to lock <0x0eeb54f1> (a java.lang.Object) held by thread 40 at android.os.storage.IMountService$Stub.onTransact(IMountService.java:1634) at android.os.Binder.execTransact(Binder.java:453) 他們均是被tid=40的人block，按照上面的方法搜尋tid=40或者 0x0eeb54f1得到block的人： "MountService" prio=5 tid=40 TimedWaiting | group="main" sCount=1 dsCount=0 obj=0x132c1160 self=0x9ce57400 | sysTid=23512 nice=0 cgrp=default sched=0/0 handle=0x9a239930 | state=S schedstat=( 0 0 0 ) utm=29 stm=2 core=2 HZ=100 | stack=0x9a137000-0x9a139000 stackSize=1038KB | held mutexes= at java.lang.Object.wait!(Native method) - waiting on <0x00fea1f3> (a java.lang.Object) at java.lang.Thread.parkFor$(Thread.java:1235) - locked <0x00fea1f3> (a java.lang.Object) at sun.misc.Unsafe.park(Unsafe.java:299) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2053) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:372) at com.android.server.NativeDaemonConnector$ResponseQueue.remove(NativeDaemonConnector.java:777) at com.android.server.NativeDaemonConnector.executeForList(NativeDaemonConnector.java:489) at com.android.server.NativeDaemonConnector.execute(NativeDaemonConnector.java:386) at com.android.server.NativeDaemonConnector.execute(NativeDaemonConnector.java:381) at com.android.server.MountService.resetIfReadyAndConnectedLocked(MountService.java:827) at com.android.server.MountService.handleSystemReady(MountService.java:776) - locked <0x0eeb54f1> (a java.lang.Object) at com.android.server.MountService.access$500(MountService.java:152) at com.android.server.MountService$MountServiceHandler.handleMessage(MountService.java:596) at android.os.Handler.dispatchMessage(Handler.java:102) at android.os.Looper.loop(Looper.java:150) at android.os.HandlerThread.run(HandlerThread.java:61) 和上面netd類似的，mountservice也是通過ndc和vold通訊，這裡我們需要繼續檢視是否vold存在異常。 之前提到過，類似這種同步鎖block的，dvm_lock_sample一定會有列印，於是先去找eventslog，不過這個是華為的log，是沒有eventlog的。 而華為實現了一個blockMonitor的功能，和dvm_lock_sample類似，當某個操作特別耗時的時候，會將其打印出來： 在ANR的附近找到如下： 07-19 10:17:50.739 25271 25271 W BlockMonitor: The binder calling took 55209ms. 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.os.BlockMonitor.checkBinderTime(BlockMonitor.java:141) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.os.BinderProxy.transact(Binder.java:511) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.os.storage.IMountService$Stub$Proxy.getVolumeList(IMountService.java:771) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.os.storage.StorageManager.getVolumeList(StorageManager.java:883) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.os.Environment$UserEnvironment.getExternalDirs(Environment.java:95) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.os.Environment.getExternalStorageDirectory(Environment.java:354) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.support.v4.content.FileProvider.parsePathStrategy(FileProvider.java:583) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.support.v4.content.FileProvider.getPathStrategy(FileProvider.java:534) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.support.v4.content.FileProvider.attachInfo(FileProvider.java:352) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.app.ActivityThread.installProvider(ActivityThread.java:5279) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.app.ActivityThread.installContentProviders(ActivityThread.java:4868) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.app.ActivityThread.handleBindApplication(ActivityThread.java:4799) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.app.ActivityThread.access$1600(ActivityThread.java:165) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.app.ActivityThread$H.handleMessage(ActivityThread.java:1436) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.os.Handler.dispatchMessage(Handler.java:102) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.os.Looper.loop(Looper.java:188) 07-19 10:17:50.739 25271 25271 W BlockMonitor: android.app.ActivityThread.main(ActivityThread.java:5578) 07-19 10:17:50.739 25271 25271 W BlockMonitor: java.lang.reflect.Method.invoke(Native Method) 07-19 10:17:50.739 25271 25271 W BlockMonitor: com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:794) 07-19 10:17:50.739 25271 25271 W BlockMonitor: com.android.internal.os.ZygoteInit.main(ZygoteInit.java:684) 再加上之前的： 07-19 10:17:50.729 22735 23512 E NativeDaemonConnector.ResponseQueue: Timeout waiting for response 07-19 10:17:50.729 22735 23512 E VoldConnector: timed-out waiting for response to 4 volume reset 07-19 10:17:50.729 22735 23512 E VoldConnector: timed-out waiting for response mOutputStream =[email protected], mSocket = vold 07-19 10:17:50.731 22735 23512 W MountService: Failed to reset vold 07-19 10:17:50.731 22735 23512 W MountService: com.android.server.NativeDaemonTimeoutException: command '4 volume reset' failed with 'null' 07-19 10:17:50.731 22735 23512 W MountService: at com.android.server.NativeDaemonConnector.executeForList(NativeDaemonConnector.java:501) 07-19 10:17:50.731 22735 23512 W MountService: at com.android.server.NativeDaemonConnector.execute(NativeDaemonConnector.java:386) 07-19 10:17:50.731 22735 23512 W MountService: at com.android.server.NativeDaemonConnector.execute(NativeDaemonConnector.java:381) 07-19 10:17:50.731 22735 23512 W MountService: at com.android.server.MountService.resetIfReadyAndConnectedLocked(MountService.java:827) 07-19 10:17:50.731 22735 23512 W MountService: at com.android.server.MountService.handleSystemReady(MountService.java:776) 07-19 10:17:50.731 22735 23512 W MountService: at com.android.server.MountService.access$500(MountService.java:152) 07-19 10:17:50.731 22735 23512 W MountService: at com.android.server.MountService$MountServiceHandler.handleMessage(MountService.java:596) 07-19 10:17:50.731 22735 23512 W MountService: at android.os.Handler.dispatchMessage(Handler.java:102) 07-19 10:17:50.731 22735 23512 W MountService: at android.os.Looper.loop(Looper.java:150) 07-19 10:17:50.731 22735 23512 W MountService: at android.os.HandlerThread.run(HandlerThread.java:61) 我們有理由去推斷vold的狀態是不對的，但是又沒有vold的棧。 那麼全域性grep vold試試能不能找到線索，在kernellog中發現了vold的異常： 07-19 14:22:24.669 <3>[10772.492156] c0 Freezing of tasks failed after 20.008 seconds (1 tasks refusing to freeze, wq_busy=0): 07-19 14:22:24.669 <6>[10772.492217] c0 vold R running 0 224 1 0x00000001 07-19 14:22:24.669 <4>[10772.492278] c0 [<c05ebecc>] (__schedule+0x38c/0x5bc) from [<c05ea478>] (schedule_timeout+0x18/0x1e8) 07-19 14:22:24.669 <4>[10772.492309] c0 [<c05ea478>] (schedule_timeout+0x18/0x1e8) from [<c05eb90c>] (wait_for_common+0x11c/0x164) 07-19 14:22:24.669 <4>[10772.492309] c0 [<c05eb90c>] (wait_for_common+0x11c/0x164) from [<c03cd8c8>] (mmc_wait_for_req+0xb4/0xe4) 07-19 14:22:24.669 <4>[10772.492339] c0 [<c03cd8c8>] (mmc_wait_for_req+0xb4/0xe4) from [<c03cd95c>] (mmc_wait_for_cmd+0x64/0x74) 07-19 14:22:24.669 <4>[10772.492370] c0 [<c03cd95c>] (mmc_wait_for_cmd+0x64/0x74) from [<c03d41f0>] (mmc_send_status+0x6c/0x8c) 07-19 14:22:24.670 <4>[10772.492400] c0 [<c03d41f0>] (mmc_send_status+0x6c/0x8c) from [<c03d4504>] (sd_send_status+0x14/0x44) 07-19 14:22:24.670 <4>[10772.492431] c0 [<c03d4504>] (sd_send_status+0x14/0x44) from [<c03d491c>] (mmc_lock_unlock_by_buf+0xac/0x168) 07-19 14:22:24.670 <4>[10772.492431] c0 [<c03d491c>] (mmc_lock_unlock_by_buf+0xac/0x168) from [<c03dabd8>] (mmc_lockable_store+0x594/0x75c) 07-19 14:22:24.670 <4>[10772.492461] c0 [<c03dabd8>] (mmc_lockable_store+0x594/0x75c) from [<c029d560>] (dev_attr_store+0x18/0x24) 07-19 14:22:32.070 <4>[10772.492492] c0 [<c029d560>] (dev_attr_store+0x18/0x24) from [<c013b370>] (sysfs_write_file+0x104/0x148) 07-19 14:22:32.070 <4>[10772.492522] c0 [<c013b370>] (sysfs_write_file+0x104/0x148) from [<c00eabb4>] (vfs_write+0xd0/0x180) 07-19 14:22:32.070 <4>[10772.492553] c0 [<c00eabb4>] (vfs_write+0xd0/0x180) from [<c00eb070>] (SyS_write+0x38/0x68) 07-19 14:22:32.071 <4>[10772.492583] c0 [<c00eb070>] (SyS_write+0x38/0x68) from [<c000e840>] (ret_fast_syscall+0x0/0x30) vold一直在這個操作中沒有退出來，所以不能響應客戶端的請求，從而導致了ANR。 這個問題需要mmc的同事進一步去分析，目前懷疑是SD卡發生了錯誤。
相關推薦
trace檔案分析ANR問題
開啟dropbox中對應的system_app_anrxxxx: 檢視主執行緒的棧： "main" prio=5 tid=1 Native | group="main" sCount=1 dsCount=0 obj=0x752b0000 self=0xb4276500 | sysT
通過Android trace檔案分析死鎖ANR
"PowerManagerService" prio=5 tid=24 MONITOR | group="main" sCount=1 dsCount=0 obj=0x41dd0eb0 self=0x5241b218 | sysTid=567 nice=0 sched=0/0 cgrp=apps ha
NS2 trace檔案分析指令碼（適合無線trace）
絡上有不少awk程式是講如何分析網路效能的（主要是時延，吞吐量，丟包率和時延抖動），但是都沒有詳細的說明，我在此作一些示例，添加了一些必要的說明註釋。 以下的內容是針對NS2模擬的結果trace檔案進行網路效能分析，看本篇前需要先行了解的的內容有：awk語言的基礎，包括語法和結構等；在Linux下
Oracle-trace檔案分析
如果一個系統的執行效率比較低，一個比較好的方法是通過跟蹤使用者的會話並且使用tkprof工具使用排序功能格式化輸出，從而找出有問題的SQL語句。例如首先從os上利用top命令找到當前佔用cpu資源最高的一個程序的PID號9999；然後在資料庫中根據PID號找到相應的sid和
Oracle效能分析：開啟SQL跟蹤和獲取trace檔案|trace檔案解讀
Oracle效能分析1：開啟SQL跟蹤和獲取trace檔案 當Oracle查詢出現效率問題時，我們往往需要了解問題所在，這樣才能針對問題給出解決方案。Oracle提供了SQL執行的trace資訊，其中包含了SQL語句的文字資訊，一些執行統計，處理過程中的等待，以及解析階段（
效能優化-Android之ANR問題分析解決 traces.txt檔案分析 CPU佔用過高
（由於公司專案特殊情況，需要使用一些小廠的三防功能手機，不能使用我們平時用的這些民用手機） 前期測試的時候是用民用手機測試的，有六七種機型（小米，華為，中興，oppo）,使用過程中均沒有出現ANR的情況，但是在公司採購的一款工程機上面用了一段時間後肯定就會出現ANR，出現了
美女程式媛發福利，讀懂ANR的trace檔案So easy
一、java執行緒的狀態轉換介紹 1.1新建狀態（New） 用new語句建立的執行緒處於新建狀態，此時它和其他Java物件一樣，僅僅在堆區中被分配了記憶體。 1.2就緒狀態（Runnable） 當一個執行緒物件建立後，其他執行緒呼叫它的start()方法，該執行緒就進入就緒狀態，Java虛
awk檔案分析
awk是行處理器: 相比較螢幕處理的優點，在處理龐大檔案時不會出現記憶體溢位或是處理緩慢的問題，通常用來格式化文字資訊 awk處理過程: 依次對每一行進行處理，然後輸出 awk命令形式: awk [-F|-f|-v] ‘BEGIN{} //{command1; command2
ARCHIVELOG模式下使用者管理恢復控制檔案—使用trace檔案重建控制檔案
首先生成控制檔案的sql指令碼 [sql] view plain copy print ? SQL> alter database backup contr
Oracle trace檔案的清理
版本：oracle 12c OS：redhat 6.4 某日，發現trace檔案有12G，trm+trc數量達到8萬個。 目錄是：/opt/oracle/diag/rdbms/orcl/ORCL/trace 本來想直接從xftp直接刪除，兩次都卡死。遂從網上找到了清理語句，記錄如下： fi
BCode解碼練習 bittorrent 學習(一) 種子檔案分析與bitmap點陣圖
在學習BT協議中的一個小練習 參考了 https://github.com/airtrack/bitwave 具體B編碼解釋 可以自行搜尋或者參考 這篇文章 bittorrent 學習(一) 種子檔案分析與bitmap點陣圖 程式碼 1 #pragma
使用10046檢視執行計劃並讀懂trace檔案
轉自：https://blog.csdn.net/dataminer_2007/article/details/42040853 檢視 sql 執行計劃的方法有許多種, 10046 事件就是其中的一種. 與其他檢視 sql 執行計劃不同, 當我們遇到比較複雜的 sql 語句, 我們可以通過 10
iOS dSYM 檔案分析
來到新公司後，前段時間就一直在忙，前不久 專案 終於成功釋出上線了，最近就在給專案做優化，並排除一些線上軟體的 bug，因為專案中使用了友盟統計，所以在友盟給出的錯誤資訊統計中能比較方便的找出客戶端異常的資訊，可是很多像陣列越界卻只給出了 *** -[__NSArrayM objectAt
LIB/PE/COFF檔案分析開源專案
這裡有一個開源專案：PE-MASTER，用來進行OBJ檔案的抽取，PE/LIB檔案分析。PE檔案修改。SVN:https://pe-master.googlecode.com/svn/trunk，如果大家對這個專案有興趣，希望加入的話，請聯絡我。
圖形化還原崩潰地址 iOS的crash檔案分析
沒有不會crash的app包括微信 沒有不會crash的程式碼即使正常執行千年 只要有會看crash的程式猿 這一週是在不同的crash日誌分析中度過的，公司的4個專案依次出現不同程式的隨機崩潰。並且出現了非常多的靈異事件，即使看到了現象程式猿（!_! ME）也很難相信這
~雜記（1）：makefile檔案分析
1、makefile 檔案分析（部分資訊，做出替換修改）。 2、相關注釋資訊作為經驗交流點。 3、如有註釋錯誤的請指正。 # = 是最基本的賦值 # := 是覆蓋之前的值 # ?= 是如果沒有被賦值過就賦予等號後面的值 # += 是新增等號後面的值 #c編譯器 CC=gcc #C+
Keil 生成的Map檔案分析
0、寫在前面 相信有較大專案開發經驗的朋友都曾遇到記憶體溢位的問題，那麼大家都是如何分析這類問題的呢？大家遇到HardFault_Handler 有對map分析過嗎？ 首先講述一下關於map在MDK-ARM中的配置。其實，在MDK-ARM中，我們可以根據自己的情況
Filebeat 原理詳解/配置檔案分析
配置檔案位置 對於rpm和deb，您將在以下位置找到配置檔案/etc/filebeat/filebeat.yml。在Docker下，它位於/usr/share/filebeat/filebeat
Arduino核心檔案分析（以Stm32duino為例）
這篇部落格主要是分析stm32duino的底層檔案結構，來分析stm32duino 的實現原理和它的基本框架。 使用的工具是Source Insight ,新建工程，新增原始碼路徑之後可以進行分析。 開啟工程原始碼的資料夾後，有四個資料夾，我們主要分
bro框架-- 檔案分析
檔案分析（File Analysis） 檔案分析框架（FAF）為檔案相關的資訊提供了一個一般的表示形式。 檔案生命週期事件（File Lifecycle Events），在一個檔案的生命週期中有file_new, file_over_new_connection, fil