前幾天騰訊將一款Android應用性能監控的框架matrix開源了,源碼地址在https://github.com/Tencent/matrix,做者是微信終端團隊。matrix究竟是什麼?據官方說法以下:
Matrix 是一款微信研發並平常使用的 APM(Application Performance Manage),當前主要運行在 Android 平臺上。 Matrix 的目標是創建統一的應用性能接入框架,經過各類性能監控方案,對性能監控項的異常數據進行採集和分析,輸出相應的問題分析、定位與優化建議,從而幫助開發者開發出更高質量的應用。
Matrix 當前監控範圍包括:應用安裝包大小,幀率變化,啓動耗時,卡頓,慢方法,SQLite 操做優化,文件讀寫,內存泄漏等等(此段截取自matrix的GitHub介紹)
下面直接看源碼:
<!-- more -->
代碼的入口在application的onCreate()裏進行初始化的,java
Matrix.Builder builder = new Matrix.Builder(this); ``` //省略了一部分構造器建立對象的一段代碼,這裏僅說明是入口 ``` Matrix.init(builder.build());
和leakcanary等庫同樣在application初始化,Matrix的建立採用了經常使用的構造器模式,如今進入Matrix內部看看android
private static volatile Matrix sInstance; private final HashSet<Plugin> plugins;//插件集合 private final Application application; private final PluginListener pluginListener; private Matrix(Application app, PluginListener listener, HashSet<Plugin> plugins) { this.application = app; this.pluginListener = listener; this.plugins = plugins; for (Plugin plugin : plugins) { plugin.init(application, pluginListener); pluginListener.onInit(plugin); } } public static void setLogIml(MatrixLog.MatrixLogImp imp) { MatrixLog.setMatrixLogImp(imp); } public static boolean isInstalled() { return sInstance != null; } public static Matrix init(Matrix matrix) { if (matrix == null) { throw new RuntimeException("Matrix init, Matrix should not be null."); } synchronized (Matrix.class) { if (sInstance == null) { sInstance = matrix; } else { MatrixLog.e(TAG, "Matrix instance is already set. this invoking will be ignored"); } } return sInstance; }
matrix裏持有一個插件的集合plugins,使用的是hashSet來保證不出現重複,還有一個plugin狀態的監聽pluginListener。Matrix採用了單例模式,volatile sInstance保證線程可見行,初始化的時候採用了雙重檢查,在構造函數裏給變量賦值並遍歷plugins集合,並逐個調用插件的初始化方法plugin.init()
。
那插件plugin是什麼呢?下面是plugin的代碼:git
public abstract class Plugin implements IPlugin, IssuePublisher.OnIssueDetectListener { private static final String TAG = "Matrix.Plugin"; public static final int PLUGIN_CREATE = 0x00; public static final int PLUGIN_INITED = 0x01; public static final int PLUGIN_STARTED = 0x02; public static final int PLUGIN_STOPPED = 0x04; public static final int PLUGIN_DESTROYED = 0x08; private PluginListener pluginListener; private Application application; private boolean isSupported = true; private int status = PLUGIN_CREATE; @Override public void init(Application app, PluginListener listener) { if (application != null || pluginListener != null) { throw new RuntimeException("plugin duplicate init, application or plugin listener is not null"); } status = PLUGIN_INITED; this.application = app; this.pluginListener = listener; } @Override public void onDetectIssue(Issue issue) { pluginListener.onReportIssue(issue); } public Application getApplication() { return application; } @Override public void start() { //省略部分代碼 pluginListener.onStart(this); } @Override public void stop() { //省略部分代碼 pluginListener.onStop(this); } @Override public void destroy() { //省略部分代碼 pluginListener.onDestroy(this); } }
plugin它是個抽象類,繼承了IPlugin和 IssuePublisher.OnIssueDetectListener,IPlugin包括了五種插件的狀態分別是CREATE
、INITED
、STARTED
、STOPPED
和DESTROYED
,當plugin狀態發生變化時將回調交給pluginListener來處理。OnIssueDetectListener接口是IssuePublisher類裏的內部接口,IssuePublisher具體作了兩件事,記錄問題和暴露問題,其暴露問題的方法就是空實現而後暴露接口,交給實現OnIssueDetectListener
接口的具體類來處理,Plugin繼承了這個OnIssueDetectListener
接口,但它也沒本身處理,也是一樣交留pluginListener來處理。github
TracePlugin
、IOCanaryPlugin
、SQLiteLintPlugin
、ResourcePlugin
。首先來看TracePlugin,它繼承自plugin,裏面包括四個維度FrameTracer
、FPSTracer
、 EvilMethodTracer
、StartUpTracer
來分析app的,初始化的方法以下:json
@Override public void init(Application app, PluginListener listener) { super.init(app, listener); MatrixLog.i(TAG, "trace plugin init, trace config: %s", mTraceConfig.toString()); //低版本不支持 if (Build.VERSION.SDK_INT < Build.VERSION_CODES.JELLY_BEAN) { MatrixLog.e(TAG, "[FrameBeat] API is low Build.VERSION_CODES.JELLY_BEAN(16), TracePlugin is not supported"); unSupportPlugin(); return; } ApplicationLifeObserver.init(app); mFrameTracer = new FrameTracer(this); //開關,能夠選擇不開 if (mTraceConfig.isMethodTraceEnable()) { mStartUpTracer = new StartUpTracer(this, mTraceConfig); } if (mTraceConfig.isFPSEnable()) { mFPSTracer = new FPSTracer(this, mTraceConfig); } if (mTraceConfig.isMethodTraceEnable()) { mEvilMethodTracer = new EvilMethodTracer(this, mTraceConfig); } }
ApplicationLifeObserver.init(app)是利用了application的ActivityLifecycleCallbacks能夠對每一個activity的生命週期進行監控作了個觀察者模式,另外加了判斷分析當前app是在前臺仍是後臺,具體實現方式是記錄onActivityResumed和onActivityPaused的生命週期,因爲新起的activity的onResume會在底層activity的onPause以後,若是onActivityPaused以後600ms沒有執行到onActivityResumed則認爲當前處於後臺。仔細想一想這麼作會有誤傷,若是有個activity啓動特別慢,此時超過600ms則斷定已經處於後臺了,不過這個影響比較小,由於activity啓動以後到resume時就又恢復成正常的前臺,即便誤判也不影響檢測,具體實現能夠看源碼。api
在TracePlugin初始化的時候,分別新建了mStartUpTracer、mFPSTracer、mFrameTracer和mEvilMethodTracer,其中的參數mTraceConfig是個簡單的配置類,只是記錄了開關就不在這展開了。查看matrix的demo開始檢測的入口是tracePlugin.start()裏,代碼以下:數組
@Override public void start() { super.start(); if (!isSupported()) { return; } new Handler(Looper.getMainLooper()).post(new Runnable() { @Override public void run() { //保證在主線程調用 FrameBeat.getInstance().onCreate(); } }); if (null != mFPSTracer) { mFPSTracer.onCreate(); } if (null != mEvilMethodTracer) { mEvilMethodTracer.onCreate(); } if (null != mFrameTracer) { mFrameTracer.onCreate(); } if (null != mStartUpTracer) { mStartUpTracer.onCreate(); } }
在onstart時在主線程中調用了FrameBeat.getInstance().onCreate(),這裏是作UI分析用的。
目前作UI性能卡頓分析通常有兩種方式:緩存
一是利用主線程looper的loop方法在尋找msg.target.dispatchMessage(msg)時的先後會分別打印一段log,能夠利用log的內容不一樣或者log的先後次數記錄兩次log的時間差,這樣就能夠大體認爲是主線程處理msg的時間,若是時間過長則認爲卡頓;微信
二是利用Choreographer,Choreographer就是一個消息處理器,根據vsync 信號 來計算frame,在doFrame方法裏能夠收到回調的當前時間,正常繪製兩次doFrame的時間差應該是1000/60=16.6666毫秒(每秒60幀),可是遇到卡頓或過分重繪等會致使時間拉長。app
這裏採用的是第二種方式,其doFrame的實現以下:
@Override public void doFrame(long frameTimeNanos) { if (isPause) { return; } if (frameTimeNanos < mLastFrameNanos || mLastFrameNanos <= 0) { mLastFrameNanos = frameTimeNanos; if (null != mChoreographer) { mChoreographer.postFrameCallback(this); } return; } if (null != mFrameListeners) { for (IFrameBeatListener listener : mFrameListeners) { listener.doFrame(mLastFrameNanos, frameTimeNanos); } if (null != mChoreographer) { mChoreographer.postFrameCallback(this); } mLastFrameNanos = frameTimeNanos; } }
記錄兩次doFrame的時間,交給mFrameListeners執行回調。
下面會分析mFPSTracer 、mFrameTracer、mFrameTracer和mStartUpTracer 的onCreate方法的具體實現,這四個類都繼承了BaseTracer類,所以在分析得前先看下BaseTracer,
public abstract class BaseTracer extends IssuePublisher implements ApplicationLifeObserver.IObserver, IFrameBeatListener, IMethodBeatListener { private final TracePlugin mPlugin; private static final MethodBeat sMethodBeat = new MethodBeat(); private static final HashMap<Class<BaseTracer>, BaseTracer> sTracerMap = new HashMap<>(); BaseTracer(TracePlugin plugin) { super(plugin); this.mPlugin = plugin; sTracerMap.put((Class<BaseTracer>) this.getClass(), this); } @Override public void doFrame(long lastFrameNanos, long frameNanos) { } public void onCreate() { MatrixLog.i(TAG, "[onCreate] name:%s process:%s", this.getClass().getCanonicalName(), Process.myPid()); if (isEnableMethodBeat()) { if (!getMethodBeat().isHasListeners()) { getMethodBeat().onCreate(); } getMethodBeat().registerListener(this); } ApplicationLifeObserver.getInstance().register(this); FrameBeat.getInstance().addListener(this); isCreated = true; } public void onDestroy() { MatrixLog.i(TAG, "[onDestroy] name:%s process:%s", this.getClass().getCanonicalName(), Process.myPid()); if (isEnableMethodBeat()) { getMethodBeat().unregisterListener(this); if (!getMethodBeat().isHasListeners()) { getMethodBeat().onDestroy(); } } ApplicationLifeObserver.getInstance().unregister(this); FrameBeat.getInstance().removeListener(this); isCreated = false; } protected void sendReport(JSONObject jsonObject, String tag) { Issue issue = new Issue(); issue.setTag(tag); issue.setContent(jsonObject); mPlugin.onDetectIssue(issue); } }
這裏截取了一部分核心的代碼,BaseTracer裏有個靜態的hashMap,類名做爲key,value是具體的BaseTracer對象,它是靜態的因此只會有一份,在onCreate裏註冊了前面說到的ApplicationLifeObserver和FrameBeat的監聽,監聽activity的生命週期的回調和Choreographer兩次繪製的時間的接口回調,回調是交給本身來處理的。另外暴露了sendReport方法,方法裏調用的是本地持有的TracePlugin對象的onDetectIssue來處理,這裏和前文Matrix裏plugins與pluginListener相對應上了,plugins裏的onDetectIssue最終都是由pluginListener來處理的。
TracePlugin分紅四個部分mStartUpTracer、mFPSTracer、mFrameTracer和mEvilMethodTracer,它們都繼承了BaseTracer;
BaseTracer裏監聽了ApplicationLifeObserver,即每一個activity的生命週期和先後臺狀態的監聽;
BaseTracer監聽着FrameBeat的每一幀刷新先後的時間即doFrame(long lastFrameNanos, long frameNanos);
下面咱們來看看mFrameTracer
mFrameTracer的具體實現的關鍵方法doFrame
@Override public void doFrame(final long lastFrameNanos, final long frameNanos) { if (!isDrawing) { return; } isDrawing = false; final int droppedCount = (int) ((frameNanos - lastFrameNanos) / REFRESH_RATE_MS); if (droppedCount > 1) { for (final IDoFrameListener listener : mDoFrameListenerList) { listener.doFrameSync(lastFrameNanos, frameNanos, getScene(), droppedCount); if (null != listener.getHandler()) { listener.getHandler().post(new Runnable() { @Override public void run() { listener.getHandler().post(new AsyncDoFrameTask(listener, lastFrameNanos, frameNanos, getScene(), droppedCount)); } }); } } } }
在doFrame里根據界面繪製的時間差計算,若是超過了正常繪製16.67秒就會在監聽裏把數據回調出去,這個有兩個回調方法doFrameSync和doFrameAsync,對應的是同步調用和異步調用,異步的實現方式利用handler機制,其中getScene是當前的activity或fragment的類名。
EvilMethodTracer顧名思義就是找到那些邪惡的方法,也就是耗時多的方法,具體實現來看代碼,
首先EvilMethodTracer繼承了LazyScheduler接口,LazyScheduler接口是個利用handler實現的定時器,代碼以下:
public class LazyScheduler { //延遲即間隔時間 private final long delay; private final Handler mHandler; private volatile boolean isSetUp = false; public LazyScheduler(HandlerThread handlerThread, long delay) { this.delay = delay; mHandler = new Handler(handlerThread.getLooper()); } public boolean isSetUp() { return isSetUp; } //開始 public void setUp(final ILazyTask task, boolean cycle) { if (null != mHandler) { this.isSetUp = true; mHandler.removeCallbacksAndMessages(null); RetryRunnable retryRunnable = new RetryRunnable(mHandler, delay, task, cycle); mHandler.postDelayed(retryRunnable, delay); } } public void cancel() { if (null != mHandler) { this.isSetUp = false; mHandler.removeCallbacksAndMessages(null); } } public void setOff() { cancel(); } public interface ILazyTask { void onTimeExpire(); } static class RetryRunnable implements Runnable { private final Handler handler; private final long delay; private final ILazyTask lazyTask; private final boolean cycle; RetryRunnable(Handler handler, long delay, ILazyTask lazyTask, boolean cycle) { this.handler = handler; this.delay = delay; this.lazyTask = lazyTask; this.cycle = cycle; } @Override public void run() { lazyTask.onTimeExpire(); if (cycle) { handler.postDelayed(this, delay); } } }
這個定時器的實現利用了handler機制,handler的looper直接從參數handlerThread的線程裏得到,這裏的代碼並不複雜,只要記住一條就能夠,一是定時器支持是否循環,執行是會調用ILazyTask的onTimeExpire方法。
EvilMethodTracer也是重寫了定時器的onTimeExpire方法,下面來看EvilMethodTracer的具體代碼。
public EvilMethodTracer(TracePlugin plugin, TraceConfig config) { super(plugin); this.mTraceConfig = config; mLazyScheduler = new LazyScheduler(MatrixHandlerThread.getDefaultHandlerThread(), Constants.DEFAULT_ANR); mActivityCreatedInfoMap = new HashMap<>(); }
建立時初始化了mLazyScheduler和mActivityCreatedInfoMap,mLazyScheduler,這裏的mLazyScheduler是個定時器Constants.DEFAULT_ANR默認值5秒,用於記錄界面5秒沒響應及ANR,中間有句MatrixHandlerThread.getDefaultHandlerThread(),MatrixHandlerThread是個hadlerThread線程管理類,它裏面包含了Matrix默認工做線程、主線程和一個動態建立新線程的容器,getDefaultHandlerThread()方法獲取的是默認工做線程的handlerThread。mActivityCreatedInfoMap是用於記錄activity的啓動耗時信息。具體是怎麼作到的呢?讓咱們一步步來看,首先啓動EvilMethodTracer的代碼以下:
@Override public void onCreate() { super.onCreate(); if (!getMethodBeat().isRealTrace()) { MatrixLog.e(TAG, "MethodBeat don't work, maybe it's wrong in trace Build!"); onDestroy(); return; } if (this.mAnalyseThread == null) { this.mAnalyseThread = MatrixHandlerThread.getNewHandlerThread("matrix_trace_analyse_thread"); mHandler = new Handler(mAnalyseThread.getLooper()); } // set up when onCreate mLazyScheduler.cancel(); if (ApplicationLifeObserver.getInstance().isForeground()) { onFront(null); } }
這裏先判斷了getMethodBeat().isRealTrace(),MethodBeat是統計ANR和超時Method的重要類,能夠說是核心類,一會在展開。
mAnalyseThread是利用MatrixHandlerThread新起了一個線程,將並它的looer交給mHandler。EvilMethodTracer從新了doFrame方法:
@Override public void doFrame(long lastFrameNanos, long frameNanos) { //isIgnoreFrame爲true的時候,一是出現了ANR,二是正在記錄方法的緩存滿了 if (isIgnoreFrame) { //清理緩存 mActivityCreatedInfoMap.clear(); //改變標識 setIgnoreFrame(false); //重置編號 getMethodBeat().resetIndex(); return; } //index指的是當前執行的方法對應緩存裏的編號 int index = getMethodBeat().getCurIndex(); //hasEntered說明activity已經存在; if (hasEntered && frameNanos - lastFrameNanos > mTraceConfig.getEvilThresholdNano()) { MatrixLog.e(TAG, "[doFrame] dropped frame too much! lastIndex:%s index:%s", 0, index); //兩幀之間相差超過一秒,將緩存裏的數據進行分析 handleBuffer(Type.NORMAL, 0, index - 1, getMethodBeat().getBuffer(), (frameNanos - lastFrameNanos) / Constants.TIME_MILLIS_TO_NANO); } //重置編號 getMethodBeat().resetIndex(); //取消mLazyScheduler,即清空對應的messageQueue mLazyScheduler.cancel(); //發送延遲消息,默認5秒,意味着五秒中以內沒有回到doframe會執行mLazyScheduler裏的runnable mLazyScheduler.setUp(this, false); }
doFrame時間差超過1秒會執行handleBuffer,時間差超過5秒會執行mLazyScheduler裏的onTimeExpire。先來看onTimeExpire方法:
public void onTimeExpire() { // 進到這裏說明doframe延遲了5秒,視爲界面的ANR //在後臺就忽略 if (isBackground()) { MatrixLog.w(TAG, "[onTimeExpire] pass this time, on Background!"); return; } //起始時間 long happenedAnrTime = getMethodBeat().getCurrentDiffTime(); MatrixLog.w(TAG, "[onTimeExpire] maybe ANR!"); //暫停一次Frame捕捉 setIgnoreFrame(true); //緩存裏的數據能夠清空 getMethodBeat().lockBuffer(false); //分析緩存,Type爲ANR handleBuffer(Type.ANR, 0, getMethodBeat().getCurIndex() - 1, getMethodBeat().getBuffer(), null, Constants.DEFAULT_ANR, happenedAnrTime, -1); }
當執行到onTimeExpire這裏若是是前臺就視爲ANR,到目前ANR的捕捉大體知道了,分析數據和doframe同樣也是執行handleBuffer,這裏也再次提到了getMethodBeat(),getMethodBeat返回的是本地持有的對象sMethodBeat,分析數據的方法handleBuffer也會用到sMethodBeat裏的東西,因此分析以前咱們先查看下MethodBeat這個類到底是作什麼的,分析MethodBeat以後再來看看handleBuffer。
MethodBeat類主要作的事是用一個數組記錄應用執行的每一個方法和方法耗時,用的是long[],使用方法id和耗時進行按位換算得要一個long值做爲元素,緩存默認長度是一百萬。在MethodBeat開始有這段代碼:
static { Hacker.hackSysHandlerCallback(); sCurrentDiffTime = sLastDiffTime = System.nanoTime() / Constants.TIME_MILLIS_TO_NANO; sReleaseBufferHandler.sendEmptyMessageDelayed(RELEASE_BUFFER_MSG_ID, Constants.DEFAULT_RELEASE_BUFFER_DELAY); }
進入Hacker.hackSysHandlerCallback
public class Hacker { private static final String TAG = "Matrix.Hacker"; public static boolean isEnterAnimationComplete = false; public static long sApplicationCreateBeginTime = 0L; public static int sApplicationCreateBeginMethodIndex = 0; public static long sApplicationCreateEndTime = 0L; public static int sApplicationCreateEndMethodIndex = 0; public static int sApplicationCreateScene = -100; public static void hackSysHandlerCallback() { try { sApplicationCreateBeginTime = System.currentTimeMillis(); sApplicationCreateBeginMethodIndex = MethodBeat.getCurIndex(); Class<?> forName = Class.forName("android.app.ActivityThread"); Field field = forName.getDeclaredField("sCurrentActivityThread"); field.setAccessible(true); Object activityThreadValue = field.get(forName); Field mH = forName.getDeclaredField("mH"); mH.setAccessible(true); Object handler = mH.get(activityThreadValue); Class<?> handlerClass = handler.getClass().getSuperclass(); Field callbackField = handlerClass.getDeclaredField("mCallback"); callbackField.setAccessible(true); Handler.Callback originalCallback = (Handler.Callback) callbackField.get(handler); HackCallback callback = new HackCallback(originalCallback); callbackField.set(handler, callback); MatrixLog.i(TAG, "hook system handler completed. start:%s", sApplicationCreateBeginTime); } catch (Exception e) { MatrixLog.e(TAG, "hook system handler err! %s", e.getCause().toString()); } }
}
這裏利用了反射機制進行了hook,代碼比較清晰,目的很明確就是利用本身寫的HackCallback來替換ActivityThread類裏的mCallback,達到偷樑換柱的效果,這樣作的意義就是能夠攔截mCallback的原有的消息,而後選擇本身要處理的消息,HackCallback裏的handleMessage實現以下:
public boolean handleMessage(Message msg) { if (msg.what == LAUNCH_ACTIVITY) { Hacker.isEnterAnimationComplete = false; } else if (msg.what == ENTER_ANIMATION_COMPLETE) { Hacker.isEnterAnimationComplete = true; } if (!isCreated) { if (msg.what == LAUNCH_ACTIVITY || msg.what == CREATE_SERVICE || msg.what == RECEIVER) { Hacker.sApplicationCreateEndTime = System.currentTimeMillis(); Hacker.sApplicationCreateEndMethodIndex = MethodBeat.getCurIndex(); Hacker.sApplicationCreateScene = msg.what; isCreated = true; } } if (null == mOriginalCallback) { return false; } return mOriginalCallback.handleMessage(msg); }
攔截到了LAUNCH_ACTIVITY和ENTER_ANIMATION_COMPLETE消息,這樣就知道當前的activity建立到完成的時機。
如今再回到MethodBeat,它繼承了IMethodBeat和ApplicationLifeObserver.IObserver接口,IObserver就是以前用於activity生命週期的監聽,IMethodBeat是用於方法緩存數據相關的。在看到這裏源碼時,我就有個疑惑,相信大多數人和我同樣會有這樣的疑惑:它是如何記錄每一個方法的,這些方法的執行時間是怎麼樣計算的?粗略看了一下MethodBeat並無找到數據的來源,可是我找到了下面這兩個個方法:
//hook method when it's called in public static void i(int methodId) { if (isBackground) { return; } if (!isRealTrace) { updateDiffTime(); sTimeUpdateHandler.sendEmptyMessage(UPDATE_TIME_MSG_ID); sBuffer = new long[Constants.BUFFER_TMP_SIZE]; } isRealTrace = true; if (isCreated && Thread.currentThread() == sMainThread) { if (sIsIn) { android.util.Log.e(TAG, "ERROR!!! MethodBeat.i Recursive calls!!!"); return; } sIsIn = true; if (sIndex >= Constants.BUFFER_SIZE) { for (IMethodBeatListener listener : sListeners) { listener.pushFullBuffer(0, Constants.BUFFER_SIZE - 1, sBuffer); } sIndex = 0; } else { mergeData(methodId, sIndex, true); } ++sIndex; sIsIn = false; } else if (!isCreated && Thread.currentThread() == sMainThread && sBuffer != null) { if (sIsIn) { android.util.Log.e(TAG, "ERROR!!! MethodBeat.i Recursive calls!!!"); return; } sIsIn = true; if (sIndex < Constants.BUFFER_TMP_SIZE) { mergeData(methodId, sIndex, true); ++sIndex; } sIsIn = false; } } //hook method when it's called out. public static void o(int methodId) { if (isBackground || null == sBuffer) { return; } if (isCreated && Thread.currentThread() == sMainThread) { if (sIndex < Constants.BUFFER_SIZE) { mergeData(methodId, sIndex, false); } else { for (IMethodBeatListener listener : sListeners) { listener.pushFullBuffer(0, Constants.BUFFER_SIZE - 1, sBuffer); } sIndex = 0; } ++sIndex; } else if (!isCreated && Thread.currentThread() == sMainThread) { if (sIndex < Constants.BUFFER_TMP_SIZE) { mergeData(methodId, sIndex, false); ++sIndex; } } }
這兩個方法的註釋很值得注意:hook method when it's called in 和hook method when it's called out,意思是經過hook來執行的,因而大體猜測它實現記錄方法的思路就是在應用運行的每一個方法以前調用i()
,在每一個方法結尾調用方法o()
,記錄方法名稱和o-i的時間差。這兩個方法的最後會執行mergeData方法:
private static void mergeData(int methodId, int index, boolean isIn) { long trueId = 0L; if (isIn) { trueId |= 1L << 63; } trueId |= (long) methodId << 43; trueId |= sCurrentDiffTime & 0x7FFFFFFFFFFL; sBuffer[index] = trueId; }
這裏的sCurrentDiffTime就是o()、i()兩個方法直接的時間差,和methodId一塊兒保存在long裏。
思路有了,它的實現方式呢?既然是用的hook,因而全局搜索了這個class的名稱,在matrix-gradle-plugin庫裏找到了MethodTracer這個類,這個類裏找到了以下這段代碼:
protected TraceMethodAdapter(int api, MethodVisitor mv, int access, String name, String desc, String className, boolean hasWindowFocusMethod, boolean isMethodBeatClass) { super(api, mv, access, name, desc); TraceMethod traceMethod = TraceMethod.create(0, access, className, name, desc); this.methodName = traceMethod.getMethodName(); this.isMethodBeatClass = isMethodBeatClass; this.hasWindowFocusMethod = hasWindowFocusMethod; this.className = className; this.name = name; } @Override protected void onMethodEnter() { TraceMethod traceMethod = mCollectedMethodMap.get(methodName); if (traceMethod != null) { traceMethodCount.incrementAndGet(); mv.visitLdcInsn(traceMethod.id); mv.visitMethodInsn(INVOKESTATIC, TraceBuildConstants.MATRIX_TRACE_CLASS, "i", "(I)V", false); } } @Override protected void onMethodExit(int opcode) { TraceMethod traceMethod = mCollectedMethodMap.get(methodName); if (traceMethod != null) { if (hasWindowFocusMethod && mTraceConfig.isActivityOrSubClass(className, mCollectedClassExtendMap) && mCollectedMethodMap.containsKey(traceMethod.getMethodName())) { TraceMethod windowFocusChangeMethod = TraceMethod.create(-1, Opcodes.ACC_PUBLIC, className, TraceBuildConstants.MATRIX_TRACE_ON_WINDOW_FOCUS_METHOD, TraceBuildConstants.MATRIX_TRACE_ON_WINDOW_FOCUS_METHOD_ARGS); if (windowFocusChangeMethod.equals(traceMethod)) { traceWindowFocusChangeMethod(mv); } } traceMethodCount.incrementAndGet(); mv.visitLdcInsn(traceMethod.id); mv.visitMethodInsn(INVOKESTATIC, TraceBuildConstants.MATRIX_TRACE_CLASS, "o", "(I)V", false); } } } private void traceApplicationContext(MethodVisitor mv, TraceMethod traceMethod) { mv.visitVarInsn(Opcodes.ALOAD, 0); mv.visitLdcInsn(traceMethod.methodName); mv.visitLdcInsn(traceMethod.desc); mv.visitMethodInsn(Opcodes.INVOKESTATIC, TraceBuildConstants.MATRIX_TRACE_CLASS, "trace", "(Ljava/lang/Object;Ljava/lang/String;Ljava/lang/String;)V", false); } private void traceWindowFocusChangeMethod(MethodVisitor mv) { mv.visitVarInsn(Opcodes.ALOAD, 0); mv.visitVarInsn(Opcodes.ILOAD, 1); mv.visitMethodInsn(Opcodes.INVOKESTATIC, TraceBuildConstants.MATRIX_TRACE_CLASS, "at", "(Landroid/app/Activity;Z)V", false);
}
這段代碼是在內部類TraceMethodAdapter裏的,這個內部類又繼承了AdviceAdapter,AdviceAdapter的實現來自引用的org.wo2.asm下的庫,從網上搜了一下,asm是個java字節碼操縱框架,它能夠直接以二進制形式動態地生成 stub 類或其餘代理類,或者在裝載時動態地修改類。ASM 提供相似於 BCEL 和 SERP 之類的工具包的功能,可是被設計得更小巧、更快速,這使它適用於實時代碼插裝。對於matrix來講,意思就是能夠利用asm這個框架進行方法的裝載,在方法前執行「com/tencent/matrix/trace/core/MethodBeat」這個class裏的i()
方法,在每一個方法最後執行o()
方法。頓時以爲漲姿式了,欲知詳情能夠本身這塊的源碼。
methodBeat裏的方法緩存的來源終於有了,如今回到EvilMethodTracer的handleBuffer分析來,先看方法源碼:
private void handleBuffer(Type type, int start, int end, long[] buffer, ViewUtil.ViewInfo viewInfo, long cost, long happenTime, int subType) { if (null == buffer) { MatrixLog.e(TAG, "null == buffer"); return; } if (cost < 0 || cost >= Constants.MAX_EVIL_METHOD_COST) { MatrixLog.e(TAG, "[analyse] trace cost invalid:%d", cost); return; } start = Math.max(0, start); end = Math.min(buffer.length - 1, end); if (start <= end) { long[] tmp = new long[end - start + 1]; System.arraycopy(buffer, start, tmp, 0, end - start + 1); if (null != mHandler) { AnalyseExtraInfo info = new AnalyseExtraInfo(type, viewInfo, cost, happenTime); info.setSubType(subType); mHandler.post(new AnalyseTask(tmp, info)); } } }
這段代碼比較簡單,意思就是截圖有效的那段數據交給mHandler所在的線程來執行,有效的數據即tmp,真正執行的是AnalyseTask的run
方法。AnalyseTask的分析方法比較長,大體的思路就是,根據存儲裏的數據即每一個方法id和執行時間,找到時間異常的方法,將異常的方法信息和一些基本信息保存在一個JSONObject裏,而後調用plugin的sendReport
方法,這裏直接截取分析後發佈的方法:
try { JSONObject jsonObject = new JSONObject(); jsonObject = DeviceUtil.getDeviceInfo(jsonObject, getPlugin().getApplication()); jsonObject.put(SharePluginInfo.ISSUE_STACK_TYPE, analyseExtraInfo.type.name()); jsonObject.put(SharePluginInfo.ISSUE_SUB_TYPE, analyseExtraInfo.subType); jsonObject.put(SharePluginInfo.ISSUE_COST, analyseExtraInfo.cost); if (analyseExtraInfo.type == Type.ENTER) { JSONObject viewInfoJson = new JSONObject(); ViewUtil.ViewInfo viewInfo = analyseExtraInfo.viewInfo; viewInfoJson.put(SharePluginInfo.ISSUE_VIEW_DEEP, null == viewInfo ? 0 : viewInfo.mViewDeep); viewInfoJson.put(SharePluginInfo.ISSUE_VIEW_COUNT, null == viewInfo ? 0 : viewInfo.mViewCount); viewInfoJson.put(SharePluginInfo.ISSUE_VIEW_ACTIVITY, null == viewInfo ? 0 : viewInfo.mActivityName); jsonObject.put(SharePluginInfo.ISSUE_VIEW_INFO, viewInfoJson); } jsonObject.put(SharePluginInfo.ISSUE_STACK, reportBuilder.toString()); jsonObject.put(SharePluginInfo.ISSUE_STACK_KEY, key); sendReport(jsonObject); } catch (JSONException e) { MatrixLog.e(TAG, "[JSONException for stack %s, error: %s", reportBuilder.toString(), e); }
最終的格式以下:
{ "machine": 2015, "detail": "ENTER", "cost": 3205, "viewInfo": { "viewDeep": 10, "viewCount": 6, "activity": "TestFpsActivity" }, "stack": "3,195,1,10\n1,33,1,58\n2,206,1,21\n3,161,1,16\n4,180,1,16\n5,169,1,16\n6,96,1,10\n7,98,1,10\n4,183,2,5\n5,211,6,0\n0,30,1,56\n", "stackKey": "0,30,1,56\n", "tag": "Trace_EvilMethod", "process": "sample.tencent.matrix" }
EvilMethodTracer就先分析到這裏,下面來看看StartUpTracer
StartUpTracer是用於分析activity的啓動時間的,以前在分析MethodBeat時提到了經過hook記錄activity在LAUNCH_ACTIVITY和ENTER_ANIMATION_COMPLETE兩個時間點,兩個時間點在這裏即是利用了起來。實現的核心方法在onActivityEntered()
裏:
String activityName = activity.getComponentName().getClassName(); if (!mActivityEnteredMap.containsKey(activityName) || isFocus) { mActivityEnteredMap.put(activityName, System.currentTimeMillis()); } if (!isFocus) { MatrixLog.i(TAG, "[onActivityEntered] isFocus false,activityName:%s", activityName); return; } if (mTraceConfig.isHasSplashActivityName() && activityName.equals(mTraceConfig.getSplashActivityName())) { MatrixLog.i(TAG, "[onActivityEntered] has splash activity! %s", mTraceConfig.getSplashActivityName()); return; } getMethodBeat().lockBuffer(false); long activityEndTime = getValueFromMap(mActivityEnteredMap, activityName); long firstActivityStart = getValueFromMap(mFirstActivityMap, mFirstActivityName); if (activityEndTime <= 0 || firstActivityStart <= 0) { MatrixLog.w(TAG, "[onActivityEntered] error activityCost! [%s:%s]", activityEndTime, firstActivityStart); mFirstActivityMap.clear(); mActivityEnteredMap.clear(); return; }
這是方法的前一段,這裏有兩個hashmap,mFirstActivityMap記錄activity在onCreate時的時間,mActivityEnteredMap記錄activity在onActivityEntered時的時間,onActivityEntered這個方法的調用是經過hook實現的在WindowFocusChange執行的,
OnActivityEnter()方法後面的內容是:
long activityCost = activityEndTime - firstActivityStart; //sApplicationCreateEndTime是methodBeat經過hook獲得的 long appCreateTime = Hacker.sApplicationCreateEndTime - Hacker.sApplicationCreateBeginTime; long betweenCost = firstActivityStart - Hacker.sApplicationCreateEndTime; long allCost = activityEndTime - Hacker.sApplicationCreateBeginTime; if (isWarnStartUp) { betweenCost = 0; allCost = activityCost; } long splashCost = 0; if (mTraceConfig.isHasSplashActivityName()) { long tmp = getValueFromMap(mActivityEnteredMap, mTraceConfig.getSplashActivityName()); splashCost = tmp == 0 ? 0 : getValueFromMap(mActivityEnteredMap, activityName) - tmp; } if (appCreateTime <= 0) { MatrixLog.e(TAG, "[onActivityEntered] appCreateTime is wrong! appCreateTime:%s", appCreateTime); mFirstActivityMap.clear(); mActivityEnteredMap.clear(); return; } if (mTraceConfig.isHasSplashActivityName() && splashCost < 0) { MatrixLog.e(TAG, "splashCost < 0! splashCost:%s", splashCost); return; } EvilMethodTracer tracer = getTracer(EvilMethodTracer.class); if (null != tracer) { long thresholdMs = isWarnStartUp ? mTraceConfig.getWarmStartUpThresholdMs() : mTraceConfig.getStartUpThresholdMs(); int startIndex = isWarnStartUp ? mFirstActivityIndex : Hacker.sApplicationCreateBeginMethodIndex; int curIndex = getMethodBeat().getCurIndex(); if (allCost > thresholdMs) { MatrixLog.i(TAG, "appCreateTime[%s] is over threshold![%s], dump stack! index[%s:%s]", appCreateTime, thresholdMs, startIndex, curIndex); EvilMethodTracer evilMethodTracer = getTracer(EvilMethodTracer.class); if (null != evilMethodTracer) { evilMethodTracer.handleBuffer(EvilMethodTracer.Type.STARTUP, startIndex, curIndex, MethodBeat.getBuffer(), appCreateTime, Constants.SUBTYPE_STARTUP_APPLICATION); } } } MatrixLog.i(TAG, "[onActivityEntered] firstActivity:%s appCreateTime:%dms betweenCost:%dms activityCreate:%dms splashCost:%dms allCost:%sms isWarnStartUp:%b ApplicationCreateScene:%s", mFirstActivityName, appCreateTime, betweenCost, activityCost, splashCost, allCost, isWarnStartUp, Hacker.sApplicationCreateScene); mHandler.post(new StartUpReportTask(activityName, appCreateTime, activityCost, betweenCost, splashCost, allCost, isWarnStartUp, Hacker.sApplicationCreateScene)); mFirstActivityMap.clear(); mActivityEnteredMap.clear(); isFirstActivityCreate = false; mFirstActivityName = null; onDestroy();
這段代碼統計了application啓動耗時、SplashActivity(歡迎頁)耗時、應用和activity之間的耗時,統計好的格式以下:
{ "machine": 4, "application_create": 415, "first_activity_create": 240, "stage_between_app_and_activity": 0, "scene": "com.tencent.mm.app.WeChatSplashActivity", "is_warm_start_up": false, "tag": "Trace_StartUp", "process": "com.tencent.mm", "time": 1528278018147 }
StartUpTracer先分析到這,還剩下最後一個FPSTracer
FPSTracer統計的是幀率,統計對應的activity、fragment的掉幀水平,利用的也是Choreographer的doFrame()
,咱們直接來看它的實現:
@Override public void doFrame(long lastFrameNanos, long frameNanos) { //isInvalid是值是否在前臺,isDrawing是否開始繪製 if (!isInvalid && isDrawing && isEnterAnimationComplete() && mTraceConfig.isTargetScene(getScene())) { //分析 handleDoFrame(lastFrameNanos, frameNanos, getScene()); } isDrawing = false; }
在開始onDraw開始後,調用了handleDoFrame
private void handleDoFrame(long lastFrameNanos, long frameNanos, String scene) { int sceneId; if (mSceneToSceneIdMap.containsKey(scene)) { sceneId = mSceneToSceneIdMap.get(scene); } else { //記錄界面的名稱和界面的編號 sceneId = mSceneToSceneIdMap.size() + 1; mSceneToSceneIdMap.put(scene, sceneId); mSceneIdToSceneMap.put(sceneId, scene); } int trueId = 0x0; trueId |= sceneId; trueId = trueId << 22; //計算此幀的耗時 long offset = frameNanos - lastFrameNanos; trueId |= ((offset / FACTOR) & 0x3FFFFF); //超過5秒 if (offset >= 5 * 1000000000L) { MatrixLog.w(TAG, "[handleDoFrame] WARNING drop frame! offset:%s scene%s", offset, scene); } synchronized (this.getClass()) { //記錄 mFrameDataList.add(trueId); } }
在這裏只是作了記錄,內部的定時器mLazyScheduler在onCreate是啓動,時間間隔默認是120秒,
public void onTimeExpire() { doReport(); }
調用doReport()
private void doReport() { LinkedList<Integer> reportList; synchronized (this.getClass()) { if (mFrameDataList.isEmpty()) { return; } reportList = mFrameDataList; mFrameDataList = new LinkedList<>(); } //reportList裏的元素包含了sceneId和幀耗時 for (int trueId : reportList) { int scene = trueId >> 22; int durTime = trueId & 0x3FFFFF; LinkedList<Integer> list = mPendingReportSet.get(scene); if (null == list) { list = new LinkedList<>(); mPendingReportSet.put(scene, list); } list.add(durTime); } reportList.clear(); //mPendingReportSet裏取到了scene和其對應的幀內容 for (int i = 0; i < mPendingReportSet.size(); i++) { int key = mPendingReportSet.keyAt(i); LinkedList<Integer> list = mPendingReportSet.get(key); if (null == list) { continue; } int sumTime = 0; int markIndex = 0; int count = 0; int[] dropLevel = new int[DropStatus.values().length]; // record the level of frames dropped each time int[] dropSum = new int[DropStatus.values().length]; // record the sum of frames dropped each time int refreshRate = (int) Constants.DEFAULT_DEVICE_REFRESH_RATE * OFFSET_TO_MS; for (Integer period : list) { sumTime += period; count++; int tmp = period / refreshRate - 1; if (tmp >= Constants.DEFAULT_DROPPED_FROZEN) { dropLevel[DropStatus.DROPPED_FROZEN.index]++; dropSum[DropStatus.DROPPED_FROZEN.index] += tmp; } else if (tmp >= Constants.DEFAULT_DROPPED_HIGH) { dropLevel[DropStatus.DROPPED_HIGH.index]++; dropSum[DropStatus.DROPPED_HIGH.index] += tmp; } else if (tmp >= Constants.DEFAULT_DROPPED_MIDDLE) { dropLevel[DropStatus.DROPPED_MIDDLE.index]++; dropSum[DropStatus.DROPPED_MIDDLE.index] += tmp; } else if (tmp >= Constants.DEFAULT_DROPPED_NORMAL) { dropLevel[DropStatus.DROPPED_NORMAL.index]++; dropSum[DropStatus.DROPPED_NORMAL.index] += tmp; } else { dropLevel[DropStatus.DROPPED_BEST.index]++; dropSum[DropStatus.DROPPED_BEST.index] += (tmp < 0 ? 0 : tmp); } if (sumTime >= mTraceConfig.getTimeSliceMs() * OFFSET_TO_MS) { // if it reaches report time float fps = Math.min(60.f, 1000.f * OFFSET_TO_MS * (count - markIndex) / sumTime); MatrixLog.i(TAG, "scene:%s fps:%s sumTime:%s [%s:%s]", mSceneIdToSceneMap.get(key), fps, sumTime, count, markIndex); try { JSONObject dropLevelObject = new JSONObject(); dropLevelObject.put(DropStatus.DROPPED_FROZEN.name(), dropLevel[DropStatus.DROPPED_FROZEN.index]); dropLevelObject.put(DropStatus.DROPPED_HIGH.name(), dropLevel[DropStatus.DROPPED_HIGH.index]); dropLevelObject.put(DropStatus.DROPPED_MIDDLE.name(), dropLevel[DropStatus.DROPPED_MIDDLE.index]); dropLevelObject.put(DropStatus.DROPPED_NORMAL.name(), dropLevel[DropStatus.DROPPED_NORMAL.index]); dropLevelObject.put(DropStatus.DROPPED_BEST.name(), dropLevel[DropStatus.DROPPED_BEST.index]); JSONObject dropSumObject = new JSONObject(); dropSumObject.put(DropStatus.DROPPED_FROZEN.name(), dropSum[DropStatus.DROPPED_FROZEN.index]); dropSumObject.put(DropStatus.DROPPED_HIGH.name(), dropSum[DropStatus.DROPPED_HIGH.index]); dropSumObject.put(DropStatus.DROPPED_MIDDLE.name(), dropSum[DropStatus.DROPPED_MIDDLE.index]); dropSumObject.put(DropStatus.DROPPED_NORMAL.name(), dropSum[DropStatus.DROPPED_NORMAL.index]); dropSumObject.put(DropStatus.DROPPED_BEST.name(), dropSum[DropStatus.DROPPED_BEST.index]); JSONObject resultObject = new JSONObject(); resultObject = DeviceUtil.getDeviceInfo(resultObject, getPlugin().getApplication()); resultObject.put(SharePluginInfo.ISSUE_SCENE, mSceneIdToSceneMap.get(key)); resultObject.put(SharePluginInfo.ISSUE_DROP_LEVEL, dropLevelObject); resultObject.put(SharePluginInfo.ISSUE_DROP_SUM, dropSumObject); resultObject.put(SharePluginInfo.ISSUE_FPS, fps); sendReport(resultObject); } catch (JSONException e) { MatrixLog.e(TAG, "json error", e); } dropLevel = new int[DropStatus.values().length]; dropSum = new int[DropStatus.values().length]; markIndex = count; sumTime = 0; } } // delete has reported data if (markIndex > 0) { for (int index = 0; index < markIndex; index++) { list.removeFirst(); } } if (!list.isEmpty()) { MatrixLog.d(TAG, "[doReport] sumTime:[%sms < %sms], scene:[%s]", sumTime / OFFSET_TO_MS, mTraceConfig.getTimeSliceMs(), mSceneIdToSceneMap.get(key)); } } }
最終解析出來的就是activity對應的幀耗時數據,數據格式以下:
{ "machine": 2015, "scene": "sample.tencent.matrix.trace.TestFpsActivity", "dropLevel": { "DROPPED_HIGH": 4, "DROPPED_MIDDLE": 12, "DROPPED_NORMAL": 18, "DROPPED_BEST": 113 }, "dropSum": { "DROPPED_HIGH": 60, "DROPPED_MIDDLE": 96, "DROPPED_NORMAL": 51, "DROPPED_BEST": 6 }, "fps": 24.476625442504883, "tag": "Trace_FPS", "process": "sample.tencent.matrix" }
目前tracePlugin的內容分析完了,其中有些數據的計算沒有去展開,你們能夠本身查看。
這裏主要分析得失TracePlugin的實現,其中包括了ANR記錄、超時函數記錄、幀數統計和啓動記錄,這還只是Plugins中的一個,內容已經顯得有點長了,因此我決定後面的IOCanaryPlugin
、SQLiteLintPlugin
、ResourcePlugin
都分紅不一樣文章來分析。
本身才疏學淺,確定有不少不足的地方,有遺漏或錯誤的地方歡迎指正。
歡迎轉載,註明出處便可,後面的文章還在書寫中。