mtk log分析

版權聲明：本文為部落客原創文章，遵循 CC 4.0 BY-SA 版權協定，轉載請附上原文出處連結和本聲明。

本文連結：https://blog.csdn.net/Zed_Faker/article/details/77159593

部落格：http://www.cnblogs.com/xiyuan2016/p/6740521.html

ZZ_INTERNAL  相關資訊及解釋

ANR,2173,-1361051648,99,/data/core/,1,system_app_anr,android.process.media,Tue Jul  4 18:51:03 HKT 2017,1

ZZ_INEERNAL包含10列，每列之間用,隔開

第一列：exception class，有KE/NE/JE/EE等

第二列：pid

第三列：tid

第四列：固定是99

第五列：固定是/data/core

第六列：exception level，0: fatal, 1: exception, 2: warning, 3: reminding

第七列：exception type info string；

如果是NE，則這個欄位是signal名稱，比如：SIGSEGV，

KE則為空，

SWT則為：system_server_watchdog，等等。

第八列：module name or process name

第九列：UTC time

第十列：固定是1

trace部分資訊解析

----- pid 2173 at 2017-07-04 11:51:32 -----

Cmd line: android.process.media

“main” prio=5 tid=1 Native

“Binder:2173_1” prio=5 tid=9 Blocked

  | group=“main” sCount=1 dsCount=0 obj=0x22c05430 self=0xa1fcab00

  | sysTid=2186 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xa497a920

  | state=S schedstat=( 26942858 122825452 281 ) utm=0 stm=2 core=0 HZ=100

  | stack=0xa487e000-0xa4880000 stackSize=1014KB

  | held mutexes=

  at com.android.providers.media.MediaProvider.getParent(MediaProvider.java:4118)

  - waiting to lock <0x06de4cd2> (a java.util.HashMap) held by thread 13

  at com.android.providers.media.MediaProvider.insertFile(MediaProvider.java:4395)

  at com.android.providers.media.MediaProvider.insertInternal(MediaProvider.java:4662)

  at com.android.providers.media.MediaProvider.insert(MediaProvider.java:4015)

  at android.content.ContentProvider$Transport.insert(ContentProvider.java:272)

  at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:163)

  at android.os.Binder.execTransact(Binder.java:570)

1)pid 2173 at 2017-07-04 11:51:32  

  >>>>ANR發生的程序的ID，時間點

2)Cmd line: android.process.media  

  >>>>ANR發生的程序的名稱

3)“main” prio=5 tid=1 Native 

  >>>>說明線程名，線程的優先級，線程鎖ID和線程狀态.

  線程名稱是啟動線程的時候手動指明的，這裡的main标示是主線程，

  是Android自動設定的一個線程名稱，如果是自己手動建立的線程，

  一般會被命名成“Thread-xx”的格式，啟動xx是線程ID，他隻增不減

  不會被複用;注意這啟動的tid不是線程的id，他是一個在Java虛拟機

  中用來實作線程鎖的變量，随着線程的增減，這個變量的值是可能被

  複用的；

4)group=“main” sCount=1 dsCount=0 obj=0x22c05430 self=0xa1fcab00

  >>>>group是線程組名稱。

  sCount是此線程被挂起的次數，

  dsCount是線程被調試器挂起的次數。

  當一個程序被調試後，sCount會重置為，調試完畢後sCount會根據是否

  被正常挂起增長，但是dsCount不會被重置為0，是以dsCount也可以用來

  判斷這個線程是否被調試過，obj表示這個線程的Java對象位址，self表

  示這個線程本身的位址。

5)此後是線程的排程資訊

| sysTid=2186 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xa497a920

  sysTid是Linux下的核心線程ID，

  nice是線程排程的優先級.

  sched分别标志了線程的排程政策和優先級，

  cgrp是排程屬組，

  handle是線程的處理函數位址。

6)線程目前上下文資訊

 | state=S schedstat=( 26942858 122825452 281 ) utm=0 stm=2 core=0 HZ=100

  state是排程狀态;

  schedstat從 /proc/[pid]/task/[tid]/schedstat讀出

  三個值分别表示線程在cpu上執行的時間、線程的等待時間和線程執行的時間片長度;

  有的android核心版本不支援這項資訊，得到的三個值都是0；utm是線程使用者态下使

  用的時間值(機關是jiffies);stm是核心态下的排程時間值;core是最後執行這個線程

  cpu核的序号

7)最後就是這個線程的排程棧資訊。

  一般可以通過以下幾個簡單的方法來判斷

  *trace檔案頂部的線程一般是ANR的元兇。

  *這是一個簡單的方法，大部分情況下都适用，可以通過這個方法來快速判斷是否是自己

   的應用造成了本次的ANR，但是并不是trace檔案包含的應用就一定是造成ANR的幫兇，應

   用出現在trace檔案中，隻能說明出現ANR的時候這個應用程序還活着，trace檔案的頂部

   則是觸發ANR的應用資訊，是以如果你的應用出現在trace檔案的頂部，那麼很有可能是

   因為你的應用造成了ANR,否則是你的應用造成ANR的可能性不大，還需要進一步分析。

8)如果定位不到時間點，可以看CPU 

  (sys_log)07-04 18:51:03.209156  1044  1068 E ANRManager: 3.4% TOTAL: 0.5% user

     + 2.6% kernel + 0.2% irq 

   從CPU使用率可以看出：

   *如果使用量很高，說明目前裝置很忙(記憶體不足，循環處理)

   *如果CPU使用量很少，說明主線程被BLOCK了

   *如果IOwait很高，說明ANR有可能是主線程在進行I/O操作造成的(資料庫、檔案操作、

    網絡操作等)      

9)等待鎖引起的ANR

  找到WallpaperManager對應代碼，再結合main log等其他資訊，看tid=27的thread在忙

  什麼。

10)SWT重新開機問題分析

  SWT是指Android Watchdog Timeout，應用層看門狗逾時，通常我們說的WDT是HWT，硬體

  看門狗逾時。

  1.Watchdog的目的是監控系統幾個比較主要的service，比如NetworkManagementService，

  PowerManagerService，ActivityManagerService等。這些Service在啟動時通過調用

  Watchdog。getInstance().addMonitor(this);加入到Watchdog的監控清單中，如果超過

  一定時間沒有反應，認為系統出錯，會強制啟動Android。

  2.Watchdog原理：/framework/base/services/java/com/android/server/Watchdog.java

  3.具體分析方法

    *首先從enventlog中以watchdog為關鍵字搜尋，記錄下這個時刻

      17:25:23.645459 950 1285 I watchdog:surfaceflinger hang.

    *然後分析所有Service Object的monitor()為何在這個時刻之前1分鐘沒有做完，

    *後面具體分析方法和ANR一樣

    *ANR是某個AP的主線程在一段時間内沒有完成某件事情，

    *Android Watchdog 是SystemServer程序的ServerThread 線程在一段時間内沒有做完

     某件事情。

radio_log分析網絡狀況

06-30 10:38:06.572525 938 976 I AT : AT< +ECSQ: 22,54,1,1,1,-36,-346,7,39 (RIL_URC_READER, tid:0)

06-30 10:38:06.572737 938 976 I RILC : RIL_SOCKET_1 UNSOLICITED: UNSOL_SIGNAL_STRENGTH length:72

06-30 10:38:06.573125 938 998 I RIL : [GSM MAL] URC send success, rid 0, ret 0:                                             #F5F6FA

06-30 10:38:06.573125 938 998 I RIL : +ECSQ: 22,54,1,1,1,-36,-346,7,39

06-30 10:38:06.574384 1028 1067 D RilMalClient: UNSOL_TO_MAL: remap to unsol resp(1009)

06-30 10:38:06.575465 1028 1067 D RpRilClientController: leave blocking write

06-30 10:38:06.575605 1028 1067 D RpRilClientController: leave blocking write

06-30 10:38:06.576133 1425 1425 D SST : [GsmSST0] handle EVENT_SIGNAL_STRENGTH_UPDATE

06-30 10:38:06.576410 1425 1425 W SignalStrength: Signal before validate=SignalStrength: 0 54 -1 -1 -1 -1 -1 99 86 9 97 2147483647 2147483647 gsm|lte 2147483647 2147483647 2147483647

06-30 10:38:06.576526 1425 1425 W SignalStrength: Signal after validate=SignalStrength: 0 54 -120 -160 -120 -1 -1 99 -86 -9 97 2147483647 2147483647 gsm|lte 2147483647 2147483647 2147483647

06-30 10:38:06.577794 1010 1367 D TelephonyRegistry: notifySignalStrengthForPhoneId: callback.onSsS r={callingPackage=android binder=android.telephony.PhoneStateListener I P h o n e S t a t e L i s t e n e r S t u b @ d 4 b 4 e d c c a l l b a c k = a n d r o i d . t e l e p h o n y . P h o n e S t a t e L i s t e n e r IPhoneStateLis[email protected] callback=android.telephony.PhoneStateListener IPhoneStateListenerStub@d4b4edccallback=android.telephony.PhoneStateListener[email protected] onSubscriptionsChangedListenererCallback=null callerUserId=0 subId=2147483647 phoneId=-1 events=1c1 canReadPhoneState=true} subId=3 phoneId=0 ss=SignalStrength: 0 54 -120 -160 -120 -1 -1 99 -86 -9 97 2147483647 2147483647 gsm|lte 2147483647 2147483647 2147483647

06-30 10:38:06.578163 1010 1367 D TelephonyRegistry: notifySignalStrengthForPhoneId: callback.onSsS r={callingPackage=com.android.systemui [email protected] callback=com.android.internal.telephony.IPhoneStateListener S t u b Stub Stub[email protected] onSubscriptionsChangedListenererCallback=null callerUserId=0 subId=3 phoneId=0 events=101e1 canReadPhoneState=true} subId=3 phoneId=0 ss=SignalStrength: 0 54 -120 -160 -120 -1 -1 99 -86 -9 97 2147483647 2147483647 gsm|lte 2147483647 2147483647 2147483647

06-30 10:38:06.578577 1010 1367 I use-Rlog/RLOG-GSM: getLTELevel - rsrp:-86 snr:97 rsrpIconLevel:3 snrIconLevel:3

06-30 10:38:06.578693 1010 1367 W SignalStrength: getLevel=3

06-30 10:38:06.579533 1305 1531 I use-Rlog/RLOG-GSM: getLTELevel - rsrp:-86 snr:97 rsrpIconLevel:3 snrIconLevel:3

06-30 10:38:06.582788 1305 1531 W SignalStrength: getLevel=3

06-30 10:38:06.588566 1305 1531 I use-Rlog/RLOG-GSM: getLTELevel - rsrp:-86 snr:97 rsrpIconLevel:3 snrIconLevel:3

06-30 10:38:06.589489 1305 1531 W SignalStrength: getLevel=3

  3G modem：

+ECSQ: , , （2G網絡）

  +ECSQ: , , , , <ec/no> （3G網絡）

  4G modem：

  +ECSQ: , , , ,1,1,1, （2G網絡）

  +ECSQ: , , , , <ec/no>,1,1, （3G網絡）

  +ECSQ: , ,1,1,1,<rsrq_qdbm >,<rsrp_qdbm> （4G網絡）

看+ECSQ 指令帶的值：

  *如果第六第七位不是255 or 1 則目前在LTE狀态，

  *如果第四第五位不是255 or 1 則目前在3G mode。

  *2G的話不是很清楚怎麼看radio log,一般是在modem log裡确認的。

  +ECSQ:,,<rssi_in_qdbm>,<rscp_in_qdbm>,<ecn0_in_qdbm>,

  <rsrq_in_qdbm>,<rsrp_in_qdbm> ,

從radio log看，手機應該在

  4G mode時。如果 SNR<0 (RSRQ<-60dbm)，則信号很差。

  3G mode時， EcN0<-15 (RSCP<-115dbm)時信号很差

  2G mode時，2G：rssi< -95dbm 、 rscq > 4 (0~7 ,0最好，7最差)

ANR 問題分析流程

1.定位問題點

  a)使用mobile log

    *events_log中搜尋am_anr

    *main_log 或 Sys_log 中搜尋ANR in

    *traces.txt中查找相應的PID或者程序名

  b) 使用anr db檔案 

    *使用gat工具打開db檔案

    *檢視ZZ_INTERNAL檔案 找到pid或者程序名

    *在SWT_JBT_TRACES查找pid

2.在mainlog中檢視cpu

  *一般在trace就能看到問題點，如果還是定位不到，就需要在mainlog中搜尋TOTAL：

  檢視CPU使用率  進而确認問題

————————————————

版權聲明：本文為CSDN部落客「Zed_Faker」的原創文章，遵循 CC 4.0 BY-SA 版權協定，轉載請附上原文出處連結及本聲明。

原文連結：https://blog.csdn.net/Zed_Faker/article/details/77159593