iOS主執行緒耗時檢測方案

前言

主執行緒耗時是一個App效能的重要指標。主執行緒阻塞，立馬會引起使用者操作的卡頓，這是最直接的反應，所以是我們必須關注的一個效能點。

檢測方案

Instrument - Time Profiler

Time Profiler模板使用Time Profiler工具對系統CPU上執行的程式執行低開銷，基於時間的取樣，顯示App對多核CPU和執行緒的使用情況。

隨著時間的推移，使用多個核心和執行緒的效率越高，App的效能就越好。

不熟悉的同學，可以參考官方文件Track CPU core and thread use

你需要在用Time Profiler之前，需要開啟生成dSYM符號檔案，否則你只能看到系統函式的呼叫。

Debug模式，預設不會生成dSYM符號檔案。

需要在Build Setting > Debug Infomation Format 選項中，為Debug開啟dSYM檔案的生成。

然後啟動Xcode，build當前專案。

再開啟Instrument，選擇Time Profiler模板，開始錄製。

Time Profiler中會記錄每個執行緒中的函式呼叫關係樹，使我們更容易定位到是哪一段程式碼導致了執行緒的阻塞。

雙擊這條記錄，就能看到這段程式碼的原始碼

OK，到此為止，Time Profiler就介紹到這裡，幾乎都是UI介面，大家很容易就能使用了。

那說說Time Profiler的缺點

• 檢測時，必須有Xcode支援。
• 真機檢測時，必須處於聯機狀態。
• 無法實現自定義的輸出內容。

自制檢測工具

Time Profiler雖然好用，但也有侷限性，這時自己搭建一套檢測工具，想必是大家都會想的事情。

這個檢測工具的功能可以參照Time Profiler

• 函式呼叫的關係樹
• 通過配置對統計資料進行篩選
• 捕獲的函式儘可能的多
• 格式化輸出統計資料
• 統計資料日誌化管理，上傳到伺服器

開始我也是從Method Swizzle思路出發，對UIViewController、UIView的耗時進行了，可惜僅僅這麼做的話，統計的顆粒度太粗了，實際用起來並不好。

hook objc_msgSend函式會是個更好的選擇。我查閱了objc4的原始碼後，發現會涉及到對C庫的Hook，以及使用匯編語言對objc_msgSend實現的重寫，執行緒的區域性儲存。

好在，iOS發展到現在，已經有很多的大神給我們提供了輪子，比如我這找到了戴銘老師的輪子進行二次封裝。

我的專案還沒整理完，不過實現原理基本借鑑了戴銘老師的設計，大家可以參考他的專案搭建自己的統計系統。

借鑑的專案地址：GCDFetchFeed

C庫的hook用的是FaceBook的fishhook，我就不多介紹了，這個大家應該耳熟能詳了吧。

此次封裝涉及檔案：

​ SMCallTrace.h ​ SMCallTrace.m ​ SMCallTraceCore.c ​ SMCallTraceCore.h

我對hook objc_msgSend方法的主要實現部分進行了程式碼註釋，希望能幫助大家理解，hook是如何完成的。

//
//  GHObjcMsgSendHook.c
//  CommercialVehiclePlatform
//
//  Created by JunhuaShao on 2019/3/17.
//  Copyright © 2019 JunhuaShao. All rights reserved.
//

/********************************************************
 objc_msgSend Hook程式碼來源：https://github.com/ming1016/GCDFetchFeed
 執行緒區域性儲存：https://blog.csdn.net/vevenlcf/article/details/77882985
 ********************************************************
 */

#import "GHObjcMsgSendHook.h"

// 此Hook只支援arm64架構
#ifdef __aarch64__

//#import <objc/runtime.h>
//#import <sys/time.h>
//
//#import <pthread.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <stddef.h>
#include <stdint.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <sys/time.h>
#include <objc/message.h>
#include <objc/runtime.h>
#include <dispatch/dispatch.h>
#include <pthread.h>

#import "fishhook.h"

/**
 Configuration
 */
// 呼叫記錄工具開關
static bool _call_record_enabled = true;
// 設定最小耗時閾值，單位：微秒
static uint64_t _min_time_cost = 1000; //us
// 設定最大呼叫深度閾值
static int _max_call_depth = 3;

/**
 iVar
 */
// 被替換的原objc_msgSend
__unused static id (*orig_objc_msgSend)(id, SEL, ...);
// 用於和呼叫執行緒關聯的key，在開啟工具時初始化
static pthread_key_t _thread_key;
// 格式化的耗時記錄
static GHCallRecord *_ghCallRecords;
// 格式化的耗時記錄佔用空間
static int _ghRecordAlloc;
// 格式化耗時記錄的個數
static int _ghRecordNum;

/**
 被hook函式的呼叫記錄
 */
typedef struct {
    // 通過 object_getClass 能夠得到 Class
    id self;
    // 通過 NSStringFromClass 能夠得到類名
    Class cls;
    // 通過 NSStringFromSelector 方法能夠得到方法名
    SEL cmd;
    // us 呼叫時間（微秒）
    uint64_t time;
    // link register 用於指定下一個函式的地址
    uintptr_t lr;
} thread_call_record;

/**
 執行緒中函式呼叫棧
 */
typedef struct {
    // 當前被hook函式的呼叫記錄
    thread_call_record *stack;
    // 當前儲存空間大小
    int allocated_length;
    // 當前記錄序號
    int index;
    // 是否在主執行緒上
    bool is_main_thread;
} thread_call_stack;

/**
 獲得執行緒中的函式呼叫棧

 @return 函式呼叫棧
 */
static inline thread_call_stack * get_thread_call_stack() {
    /**
     int pthread_setspecific (pthread_key_t key, const void *value)
     用於將value的副本儲存於一資料結構中，並將其與呼叫執行緒以及key相關聯。
     引數value通常指向由呼叫者分配的一塊記憶體。
     當執行緒終止時，會將該指標作為引數傳遞給與key相關聯的destructor函式。
     
     void *pthread_getspecific (pthread_key_t key);
     當執行緒被建立時，會將所有的執行緒區域性儲存變數初始化為NULL。
     因此第一次使用此類變數前必須先呼叫pthread_getspecific()函式來確認是否已經於對應的key相關聯，
     如果沒有，那麼可以通過分配一塊記憶體並通過pthread_setspecific()函式儲存指向該記憶體塊的指標。
     */
    thread_call_stack *cs = (thread_call_stack *)pthread_getspecific(_thread_key);
    if (cs == NULL) {
        // 為函式呼叫棧開闢空間
        cs = (thread_call_stack *)malloc(sizeof(thread_call_stack));
        // 為hook函式記錄開闢空間，大小為128個記錄大小
        cs->stack = (thread_call_record *)calloc(128, sizeof(thread_call_record));
        // 初始當前儲存空間為64個記錄大小
        cs->allocated_length = 64;
        // 初始化序號
        cs->index = -1;
        /**
         int pthread_main_np(void); 如果在主執行緒上，會返回不為零的結果
         */
        cs->is_main_thread = pthread_main_np();
        // 將呼叫棧與執行緒關聯
        pthread_setspecific(_thread_key, cs);
    }
    return cs;
}

static void release_thread_call_stack(void *ptr) {
    thread_call_stack *cs = (thread_call_stack *)ptr;
    if (!cs) return;
    // 釋放呼叫棧
    if (cs->stack) free(cs->stack);
    free(cs);
}

static inline void push_call_record(id _self, Class _cls, SEL _cmd, uintptr_t lr) {
    // 獲得當前執行緒關聯的呼叫棧
    thread_call_stack *cs = get_thread_call_stack();
    if (cs) {
        // 序號增一
        int nextIndex = (++cs->index);
        // 如果序號超過了當前儲存空間大小
        if (nextIndex >= cs->allocated_length) {
            // 將當前儲存空間增長64個記錄大小
            cs->allocated_length += 64;
            // 為指標重新分配呼叫棧的空間，為當前儲存空間大小。
            cs->stack = (thread_call_record *)realloc(cs->stack, cs->allocated_length * sizeof(thread_call_record));
        }
        // 獲得當前序號對應的記憶體地址，建立新記錄
        thread_call_record *newRecord = &cs->stack[nextIndex];
        // 記錄呼叫物件
        newRecord->self = _self;
        // 記錄呼叫class
        newRecord->cls = _cls;
        // 記錄呼叫函式
        newRecord->cmd = _cmd;
        // 記錄下一個呼叫函式地址
        newRecord->lr = lr;
        /**
         當前執行緒為主執行緒，並且開啟了呼叫記錄功能。
         目的是隻統計主執行緒耗時
        */
        if (cs->is_main_thread && _call_record_enabled) {
            /**
             Linux定義的timeval結構體
             __darwin_time_t            tv_sec;            //seconds
             __darwin_suseconds_t    tv_usec;        //and microseconds
             
             tv_sec為Epoch到建立struct timeval時的秒數，
             tv_usec為微秒數，即秒後面的零頭。
             這裡用了高精度，所以對兩者進行了相加，取了最近的100秒
             */
            struct timeval now;
            // 獲得當前時間
            gettimeofday(&now, NULL);
            newRecord->time = (now.tv_sec % 100) * 1000000 + now.tv_usec;
        }
    }
}

static inline uintptr_t pop_call_record() {
    // 獲取當前呼叫棧
    thread_call_stack *cs = get_thread_call_stack();
    // 當前呼叫記錄序號
    int curIndex = cs->index;
    // 父級函式呼叫記錄序號
    int nextIndex = cs->index--;
    // 獲取父級函式呼叫記錄，出棧
    thread_call_record *pRecord = &cs->stack[nextIndex];
    // 同樣是主執行緒，並且開啟記錄功能
    if (cs->is_main_thread && _call_record_enabled) {
        // 獲取當前時間
        struct timeval now;
        gettimeofday(&now, NULL);
        uint64_t time = (now.tv_sec % 100) * 1000000 + now.tv_usec;
        // 如果當前時間小於上次記錄的時間，則進位了，這裡加上100秒
        if (time < pRecord->time) {
            time += 100 * 1000000;
        }
        // 獲得耗時
        uint64_t cost = time - pRecord->time;
        // 耗時大於耗時閾值，呼叫深度小於最大深度，則進行記錄。這裡呼叫序號，即為深度
        if (cost > _min_time_cost && cs->index < _max_call_depth) {
            // 初始化格式化耗時記錄
            if (!_ghCallRecords) {
                // 建立空間大小為1024個記錄
                _ghRecordAlloc = 1024;
                _ghCallRecords = (GHCallRecord *)malloc(sizeof(GHCallRecord)*_ghRecordAlloc);
                
            }
            // 記錄個數加一
            _ghRecordNum++;
            // 當前記錄個數大於空間時，重新為指標分配記憶體，大小為比原來多1024個記錄
            if (_ghRecordNum >= _ghRecordAlloc) {
                _ghRecordAlloc += 1024;
                _ghCallRecords = (GHCallRecord *)realloc(_ghCallRecords, sizeof(GHCallRecord) * _ghRecordAlloc);
            }
            // 獲取當前頁數對應的地址，建立格式化記錄。
            GHCallRecord *log = &_ghCallRecords[_ghRecordNum - 1];
            // 儲存呼叫class
            log->cls = pRecord->cls;
            // 儲存呼叫深度
            log->depth = curIndex;
            // 儲存呼叫方法
            log->sel = pRecord->cmd;
            // 儲存耗時
            log->time = cost;
        }
    }
    // 返回下個函式的呼叫地址
    return pRecord->lr;
}

void hook_before_objc_msgSend(id self, SEL _cmd, uintptr_t lr)
{
    // 函式呼叫記錄入棧
    push_call_record(self, object_getClass(self), _cmd, lr);
}

uintptr_t hook_after_objc_msgSend() {
    // 函式呼叫記錄出棧
    return pop_call_record();
}
// replacement objc_msgSend (arm64)
// https://blog.nelhage.com/2010/10/amd64-and-va_arg/
// http://infocenter.arm.com/help/topic/com.arm.doc.ihi0055b/IHI0055B_aapcs64.pdf
// https://developer.apple.com/library/ios/documentation/Xcode/Conceptual/iPhoneOSABIReference/Articles/ARM64FunctionCallingConventions.html
#define call(b, value) \
__asm volatile ("stp x8, x9, [sp, #-16]!\n"); \
__asm volatile ("mov x12, %0\n" :: "r"(value)); \
__asm volatile ("ldp x8, x9, [sp], #16\n"); \
__asm volatile (#b " x12\n");

#define save() \
__asm volatile ( \
"stp x8, x9, [sp, #-16]!\n" \
"stp x6, x7, [sp, #-16]!\n" \
"stp x4, x5, [sp, #-16]!\n" \
"stp x2, x3, [sp, #-16]!\n" \
"stp x0, x1, [sp, #-16]!\n");

#define load() \
__asm volatile ( \
"ldp x0, x1, [sp], #16\n" \
"ldp x2, x3, [sp], #16\n" \
"ldp x4, x5, [sp], #16\n" \
"ldp x6, x7, [sp], #16\n" \
"ldp x8, x9, [sp], #16\n" );

#define link(b, value) \
__asm volatile ("stp x8, lr, [sp, #-16]!\n"); \
__asm volatile ("sub sp, sp, #16\n"); \
call(b, value); \
__asm volatile ("add sp, sp, #16\n"); \
__asm volatile ("ldp x8, lr, [sp], #16\n");

#define ret() __asm volatile ("ret\n");

__attribute__((__naked__))
static void hook_Objc_msgSend() {
    // Save parameters.
    save();
    
    __asm volatile ("mov x2, lr\n");
    __asm volatile ("mov x3, x4\n");
    
    // Call our before_objc_msgSend.
    call(blr, &hook_before_objc_msgSend);
    
    // Load parameters.
    load();
    
    // Call through to the original objc_msgSend.
    call(blr, orig_objc_msgSend);
    
    // Save original objc_msgSend return value.
    save();
    
    // Call our after_objc_msgSend.
    call(blr, &hook_after_objc_msgSend);
    
    // restore lr
    __asm volatile ("mov lr, x0\n");
    
    // Load original objc_msgSend return value.
    load();
    
    // return
    ret();
}

void ghAnalyerStart() {
    _call_record_enabled = true;
    static dispatch_once_t onceToken;
    dispatch_once(&onceToken, ^{
        pthread_key_create(&_thread_key, &release_thread_call_stack);
        rebind_symbols((struct rebinding[6]){
            {"objc_msgSend", (void *)hook_Objc_msgSend, (void **)&orig_objc_msgSend},
        }, 1);
    });
}

void ghAnalyerStop() {
    _call_record_enabled = false;
}

void ghSetMinTimeCallCost(uint64_t us) {
    _min_time_cost = us;
}
void ghSetMaxCallDepth(int depth) {
    _max_call_depth = depth;
}

GHCallRecord *ghGetCallRecords(int *num) {
    if (num) {
        *num = _ghRecordNum;
    }
    return _ghCallRecords;
}

void ghClearCallRecords() {
    if (_ghCallRecords) {
        free(_ghCallRecords);
        _ghCallRecords = NULL;
    }
    _ghRecordNum = 0;
}

#else

void ghAnalyerStart() {}
void ghAnalyerStop() {}
void ghSetMinTimeCallCost(uint64_t us) {
}
void ghSetMaxCallDepth(int depth) {
}
GHCallRecord *ghGetCallRecords(int *num) {
    if (num) {
        *num = 0;
    }
    return NULL;
}
void ghClearCallRecords() {}

#endif

/**
 下面是Hook objc_msgSend的相關部分彙編原始碼
 .macro MethodTableLookup
 
 // push frame
 SignLR
 stp    fp, lr, [sp, #-16]!
 mov    fp, sp
 
 // save parameter registers: x0..x8, q0..q7
 sub    sp, sp, #(10*8 + 8*16)
 stp    q0, q1, [sp, #(0*16)]
 stp    q2, q3, [sp, #(2*16)]
 stp    q4, q5, [sp, #(4*16)]
 stp    q6, q7, [sp, #(6*16)]
 stp    x0, x1, [sp, #(8*16+0*8)]
 stp    x2, x3, [sp, #(8*16+2*8)]
 stp    x4, x5, [sp, #(8*16+4*8)]
 stp    x6, x7, [sp, #(8*16+6*8)]
 str    x8,     [sp, #(8*16+8*8)]
 
 // receiver and selector already in x0 and x1
 mov    x2, x16
 bl    __class_lookupMethodAndLoadCache3
 
 // IMP in x0
 mov    x17, x0
 
 // restore registers and return
 ldp    q0, q1, [sp, #(0*16)]
 ldp    q2, q3, [sp, #(2*16)]
 ldp    q4, q5, [sp, #(4*16)]
 ldp    q6, q7, [sp, #(6*16)]
 ldp    x0, x1, [sp, #(8*16+0*8)]
 ldp    x2, x3, [sp, #(8*16+2*8)]
 ldp    x4, x5, [sp, #(8*16+4*8)]
 ldp    x6, x7, [sp, #(8*16+6*8)]
 ldr    x8,     [sp, #(8*16+8*8)]
 
 mov    sp, fp
 ldp    fp, lr, [sp], #16
 AuthenticateLR
 
 .endmacro
 */

複製程式碼