前言
在移動(dòng)設(shè)備上開發(fā)軟件,性能一直是我們最為關(guān)心的話題之一,我們作為程序員除了需要努力提高代碼質(zhì)量之外,及時(shí)發(fā)現(xiàn)和監(jiān)控軟件中那些造成性能低下的”罪魁禍?zhǔn)住币彩俏覀兩袷サ穆氊?zé)。
眾所周知,iOS平臺(tái)因?yàn)閁IKit本身的特性,需要將所有的UI操作都放在主線程執(zhí)行,所以也造成不少程序員都習(xí)慣將一些線程安全性不確定的邏輯,以及其它線程結(jié)束后的匯總工作等等放到了主線,所以主線程中包含的這些大量計(jì)算、IO、繪制都有可能造成卡頓。
在Xcode中已經(jīng)集成了非常方便的調(diào)試工具Instruments,它可以幫助我們?cè)陂_發(fā)測(cè)試階段分析軟件運(yùn)行的性能消耗,但一款軟件經(jīng)過測(cè)試流程和實(shí)驗(yàn)室分析肯定是不夠的,在正式環(huán)境中由大量用戶在使用過程中監(jiān)控、分析到的數(shù)據(jù)更能解決一些隱藏的問題。
什么原因?qū)е铝丝D
- 死鎖
- 搶鎖
- 大量的Ui繪制,復(fù)雜的UI，圖文混排
- 主線程大量IO、大量計(jì)算
相關(guān)知識(shí)補(bǔ)充 - 信號(hào)量
信號(hào)量就是一個(gè)資源計(jì)數(shù)器，對(duì)信號(hào)量有兩個(gè)操作來達(dá)到互斥，分別是P和V操作。 一般情況是這樣進(jìn)行臨界訪問或互斥訪問的： 設(shè)信號(hào)量值為1， 當(dāng)一個(gè)進(jìn)程1運(yùn)行時(shí)，使用資源，進(jìn)行P操作，即對(duì)信號(hào)量值減1，也就是資源數(shù)少了1個(gè)，這時(shí)信號(hào)量值為0。
系統(tǒng)中規(guī)定當(dāng)信號(hào)量值為0時(shí)，必須等待，直到信號(hào)量值不為零才能繼續(xù)操作。 這時(shí)如果進(jìn)程2想要運(yùn)行，那么也必須進(jìn)行P操作，但是此時(shí)信號(hào)量為0，所以無法減1，即不能P操作，也就阻塞，這樣就到到了進(jìn)程1排他訪問。
當(dāng)進(jìn)程1運(yùn)行結(jié)束后，釋放資源，進(jìn)行V操作。資源數(shù)重新加1，這時(shí)信號(hào)量的值變?yōu)?. 這時(shí)進(jìn)程2發(fā)現(xiàn)資源數(shù)不為0，信號(hào)量能進(jìn)行P操作了，立即執(zhí)行P操作。信號(hào)量值又變?yōu)?，這時(shí)進(jìn)程2有資源，排他訪問資源。 這就是信號(hào)量來控制互斥的原理。
卡頓困難點(diǎn)
不易重現(xiàn)
可能是特定用戶的手機(jī)上才有問題，由于種種原因這個(gè)手機(jī)不能拿來調(diào)試；也有可能是特定的時(shí)機(jī)才會(huì)出問題，過后就不能重現(xiàn)了（例如線程搶鎖）。操作路徑長(zhǎng)，日志無法準(zhǔn)確打點(diǎn)
對(duì)于這些界面卡頓反饋，通常我們拿用戶日志作用不大，增加日志點(diǎn)也用處不大。只能不斷重試希望能夠重現(xiàn)出來，或者埋頭代碼邏輯中試圖能找的蛛絲馬跡
尋找卡頓切入點(diǎn)
監(jiān)控卡頓,最直接就是找到主線程都在干些啥玩意兒.我們知道一個(gè)線程的消息事件處理都是依賴于NSRunLoop來驅(qū)動(dòng),所以要知道線程正在調(diào)用什么方法,就需要從NSRunLoop來入手.CFRunLoop的代碼是開源,可以在此處查閱到 CFRunLoop.c 源代碼
其中核心方法CFRunLoopRun簡(jiǎn)化后的主要邏輯大概是這樣的:
/// 1. 通知Observers，即將進(jìn)入RunLoop
/// 此處有Observer會(huì)創(chuàng)建AutoreleasePool: _objc_autoreleasePoolPush();
__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopEntry);
do {
/// 2. 通知 Observers: 即將觸發(fā) Timer 回調(diào)。
__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopBeforeTimers);
/// 3. 通知 Observers: 即將觸發(fā) Source (非基于port的,Source0) 回調(diào)。
__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopBeforeSources);
__CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__(block);
/// 4. 觸發(fā) Source0 (非基于port的) 回調(diào)。
__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__(source0);
/// 5. GCD處理main block
__CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__(block);
/// 6. 通知Observers，即將進(jìn)入休眠
/// 此處有Observer釋放并新建AutoreleasePool: _objc_autoreleasePoolPop(); _objc_autoreleasePoolPush();
__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopBeforeWaiting);
/// 7. sleep to wait msg.
mach_msg() -> mach_msg_trap();
/// 8. 通知Observers，線程被喚醒
__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopAfterWaiting);
/// 9. 如果是被Timer喚醒的，回調(diào)Timer
__CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__(timer);
/// 9. 如果是被dispatch喚醒的，執(zhí)行所有調(diào)用 dispatch_async 等方法放入main queue 的 block
__CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__(dispatched_block);
/// 9. 如果如果Runloop是被 Source1 (基于port的) 的事件喚醒了，處理這個(gè)事件
__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__(source1);
} while (...);
/// 10. 通知Observers，即將退出RunLoop
/// 此處有Observer釋放AutoreleasePool: _objc_autoreleasePoolPop();
__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopExit);
}
不難發(fā)現(xiàn)NSRunLoop調(diào)用方法主要就是在kCFRunLoopBeforeSources和kCFRunLoopBeforeWaiting之間,還有kCFRunLoopAfterWaiting之后,也就是如果我們發(fā)現(xiàn)這兩個(gè)時(shí)間內(nèi)耗時(shí)太長(zhǎng),那么就可以判定出此時(shí)主線程卡頓。
量化卡頓的程度
要監(jiān)控NSRunLoop的狀態(tài),我們需要使用到CFRunLoopObserverRef,通過它可以實(shí)時(shí)獲得這些狀態(tài)值的變化,具體的使用如下:
static void runLoopObserverCallBack(CFRunLoopObserverRef observer, CFRunLoopActivity activity, void *info)
{
MyClass *object = (__bridge MyClass*)info;
object->activity = activity;
}
- (void)registerObserver
{
CFRunLoopObserverContext context = {0,(__bridge void*)self,NULL,NULL};
CFRunLoopObserverRef observer = CFRunLoopObserverCreate(kCFAllocatorDefault,
kCFRunLoopAllActivities,
YES,
0,
&runLoopObserverCallBack,
&context);
CFRunLoopAddObserver(CFRunLoopGetMain(), observer, kCFRunLoopCommonModes);
}
其中UI主要集中在__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__(source0);
和__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__(source1);之前。
獲取kCFRunLoopBeforeSources到kCFRunLoopBeforeWaiting再到kCFRunLoopAfterWaiting的狀態(tài)就可以知道是否有卡頓的情況。
實(shí)現(xiàn)思路：只需要另外再開啟一個(gè)線程,實(shí)時(shí)計(jì)算這兩個(gè)狀態(tài)區(qū)域之間的耗時(shí)是否到達(dá)某個(gè)閥值,便能揪出這些性能殺手。
- 監(jiān)聽
runloop狀態(tài)變化
// 就是runloop有一個(gè)狀態(tài)改變 就記錄一下
static void runLoopObserverCallBack(CFRunLoopObserverRef observer, CFRunLoopActivity activity, void *info) {
BGPerformanceMonitor *monitor = (__bridge BGPerformanceMonitor*)info;
// 記錄狀態(tài)值
monitor->activity = activity;
// 發(fā)送信號(hào)
dispatch_semaphore_t semaphore = monitor->semaphore;
long st = dispatch_semaphore_signal(semaphore);
NSLog(@"dispatch_semaphore_signal:st=%ld,time:%@",st,[BGPerformanceMonitor getCurTime]);
/* Run Loop Observer Activities */
// typedef CF_OPTIONS(CFOptionFlags, CFRunLoopActivity) {
// kCFRunLoopEntry = (1UL << 0), // 進(jìn)入RunLoop循環(huán)(這里其實(shí)還沒進(jìn)入)
// kCFRunLoopBeforeTimers = (1UL << 1), // RunLoop 要處理timer了
// kCFRunLoopBeforeSources = (1UL << 2), // RunLoop 要處理source了
// kCFRunLoopBeforeWaiting = (1UL << 5), // RunLoop要休眠了
// kCFRunLoopAfterWaiting = (1UL << 6), // RunLoop醒了
// kCFRunLoopExit = (1UL << 7), // RunLoop退出（和kCFRunLoopEntry對(duì)應(yīng)）
// kCFRunLoopAllActivities = 0x0FFFFFFFU
// };
if (activity == kCFRunLoopEntry) { // 即將進(jìn)入RunLoop
NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopEntry");
} else if (activity == kCFRunLoopBeforeTimers) { // 即將處理Timer
NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopBeforeTimers");
} else if (activity == kCFRunLoopBeforeSources) { // 即將處理Source
NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopBeforeSources");
} else if (activity == kCFRunLoopBeforeWaiting) { //即將進(jìn)入休眠
NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopBeforeWaiting");
} else if (activity == kCFRunLoopAfterWaiting) { // 剛從休眠中喚醒
NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopAfterWaiting");
} else if (activity == kCFRunLoopExit) { // 即將退出RunLoop
NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopExit");
} else if (activity == kCFRunLoopAllActivities) {
NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopAllActivities");
}
}
- 開啟
runloop監(jiān)聽
// 開始監(jiān)聽
- (void)startMonitor {
if (observer) {
return;
}
// 創(chuàng)建信號(hào)
semaphore = dispatch_semaphore_create(0);
NSLog(@"dispatch_semaphore_create:%@",[BGPerformanceMonitor getCurTime]);
// 注冊(cè)RunLoop狀態(tài)觀察
CFRunLoopObserverContext context = {0,(__bridge void*)self,NULL,NULL};
//創(chuàng)建Run loop observer對(duì)象
//第一個(gè)參數(shù)用于分配observer對(duì)象的內(nèi)存
//第二個(gè)參數(shù)用以設(shè)置observer所要關(guān)注的事件，詳見回調(diào)函數(shù)myRunLoopObserver中注釋
//第三個(gè)參數(shù)用于標(biāo)識(shí)該observer是在第一次進(jìn)入run loop時(shí)執(zhí)行還是每次進(jìn)入run loop處理時(shí)均執(zhí)行
//第四個(gè)參數(shù)用于設(shè)置該observer的優(yōu)先級(jí)
//第五個(gè)參數(shù)用于設(shè)置該observer的回調(diào)函數(shù)
//第六個(gè)參數(shù)用于設(shè)置該observer的運(yùn)行環(huán)境
observer = CFRunLoopObserverCreate(kCFAllocatorDefault,
kCFRunLoopAllActivities,
YES,
0,
&runLoopObserverCallBack,
&context);
CFRunLoopAddObserver(CFRunLoopGetMain(), observer, kCFRunLoopCommonModes);
// 在子線程監(jiān)控時(shí)長(zhǎng)
dispatch_async(dispatch_get_global_queue(0, 0), ^{
while (YES) { // 有信號(hào)的話 就查詢當(dāng)前runloop的狀態(tài)
// 假定連續(xù)5次超時(shí)50ms認(rèn)為卡頓(當(dāng)然也包含了單次超時(shí)250ms)
// 因?yàn)橄旅?runloop 狀態(tài)改變回調(diào)方法runLoopObserverCallBack中會(huì)將信號(hào)量遞增 1,所以每次 runloop 狀態(tài)改變后,下面的語(yǔ)句都會(huì)執(zhí)行一次
// dispatch_semaphore_wait:Returns zero on success, or non-zero if the timeout occurred.
long st = dispatch_semaphore_wait(semaphore, dispatch_time(DISPATCH_TIME_NOW, 50*NSEC_PER_MSEC));
NSLog(@"dispatch_semaphore_wait:st=%ld,time:%@",st,[self getCurTime]);
if (st != 0) { // 信號(hào)量超時(shí)了 - 即 runloop 的狀態(tài)長(zhǎng)時(shí)間沒有發(fā)生變更,長(zhǎng)期處于某一個(gè)狀態(tài)下
if (!observer) {
timeoutCount = 0;
semaphore = 0;
activity = 0;
return;
}
NSLog(@"st = %ld,activity = %lu,timeoutCount = %d,time:%@",st,activity,timeoutCount,[self getCurTime]);
// kCFRunLoopBeforeSources - 即將處理source kCFRunLoopAfterWaiting - 剛從休眠中喚醒
// 獲取kCFRunLoopBeforeSources到kCFRunLoopBeforeWaiting再到kCFRunLoopAfterWaiting的狀態(tài)就可以知道是否有卡頓的情況。
// kCFRunLoopBeforeSources:停留在這個(gè)狀態(tài),表示在做很多事情
if (activity == kCFRunLoopBeforeSources || activity == kCFRunLoopAfterWaiting) { // 發(fā)生卡頓,記錄卡頓次數(shù)
if (++timeoutCount < 5) {
continue; // 不足 5 次,直接 continue 當(dāng)次循環(huán),不將timeoutCount置為0
}
// 收集Crash信息也可用于實(shí)時(shí)獲取各線程的調(diào)用堆棧
PLCrashReporterConfig *config = [[PLCrashReporterConfig alloc] initWithSignalHandlerType:PLCrashReporterSignalHandlerTypeBSD symbolicationStrategy:PLCrashReporterSymbolicationStrategyAll];
PLCrashReporter *crashReporter = [[PLCrashReporter alloc] initWithConfiguration:config];
NSData *data = [crashReporter generateLiveReport];
PLCrashReport *reporter = [[PLCrashReport alloc] initWithData:data error:NULL];
NSString *report = [PLCrashReportTextFormatter stringValueForCrashReport:reporter withTextFormat:PLCrashReportTextFormatiOS];
NSLog(@"---------卡頓信息\n%@\n--------------",report);
}
}
NSLog(@"dispatch_semaphore_wait timeoutCount = 0，time:%@",[self getCurTime]);
timeoutCount = 0;
}
});
}
記錄卡頓的函數(shù)調(diào)用
監(jiān)控到了卡頓現(xiàn)場(chǎng),當(dāng)然下一步便是記錄此時(shí)的函數(shù)調(diào)用信息,此處可以使用一個(gè)第三方Crash收集組件PLCrashReporter,它不僅可以收集Crash信息也可用于實(shí)時(shí)獲取各線程的調(diào)用堆棧,使用示例如下:
PLCrashReporterConfig *config = [[PLCrashReporterConfig alloc] initWithSignalHandlerType:PLCrashReporterSignalHandlerTypeBSD
symbolicationStrategy:PLCrashReporterSymbolicationStrategyAll];
PLCrashReporter *crashReporter = [[PLCrashReporter alloc] initWithConfiguration:config];
NSData *data = [crashReporter generateLiveReport];
PLCrashReport *reporter = [[PLCrashReport alloc] initWithData:data error:NULL];
NSString *report = [PLCrashReportTextFormatter stringValueForCrashReport:reporter
withTextFormat:PLCrashReportTextFormatiOS];
NSLog(@"------------\n%@\n------------", report);
當(dāng)檢測(cè)到卡頓時(shí),抓取堆棧信息,然后在客戶端做一些過濾處理,便可以上報(bào)到服務(wù)器,通過收集一定量的卡頓數(shù)據(jù)后經(jīng)過分析便能準(zhǔn)確定位需要優(yōu)化的邏輯,至此這個(gè)實(shí)時(shí)卡頓監(jiān)控就大功告成了!
測(cè)試用例
寫一個(gè)tableView視圖，上下拖動(dòng)，并人為設(shè)置卡頓(休眠)
- (NSInteger)tableView:(UITableView *)tableView numberOfRowsInSection:(NSInteger)section {
return 100;
}
- (UITableViewCell *)tableView:(UITableView *)tableView cellForRowAtIndexPath:(NSIndexPath *)indexPath {
UITableViewCell *cell = [tableView dequeueReusableCellWithIdentifier:@"cell"];
if (!cell) {
cell = [[UITableViewCell alloc] initWithStyle:UITableViewCellStyleDefault reuseIdentifier:@"cell"];
}
NSString *text = nil;
if (indexPath.row % 10 == 0) { // 每10行休眠0.2S
usleep(500 * 1000); // 1 * 1000 * 1000 == 1秒
text = @"我在做復(fù)雜的事情，需要一些時(shí)間";
} else {
text = [NSString stringWithFormat:@"cell - %ld",indexPath.row];
}
cell.textLabel.text = text;
return cell;
}
運(yùn)行結(jié)果一
2019-06-27 19:22:35.898214+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopAfterWaiting
2019-06-27 19:22:35.899001+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:899
2019-06-27 19:22:35.899395+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-06-27 19:22:35.900216+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:900
2019-06-27 19:22:35.900425+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
2019-06-27 19:22:35.903171+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:903
2019-06-27 19:22:35.903317+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-06-27 19:22:35.903563+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:903
2019-06-27 19:22:35.903722+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
2019-06-27 19:22:35.904127+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:904
2019-06-27 19:22:35.904372+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeWaiting
2019-06-27 19:22:35.901860+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait timeoutCount = 0，time:2019/06/27 07:22:35:898
2019-06-27 19:22:35.906158+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=0,time:2019/06/27 07:22:35:906
2019-06-27 19:22:35.914693+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:914
2019-06-27 19:22:35.915027+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopAfterWaiting
2019-06-27 19:22:35.917535+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:916
2019-06-27 19:22:35.918352+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-06-27 19:22:35.919467+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:919
2019-06-27 19:22:35.919853+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
2019-06-27 19:22:35.920694+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:920
2019-06-27 19:22:35.921004+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeWaiting
2019-06-27 19:22:35.925240+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:925
2019-06-27 19:22:35.925425+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopAfterWaiting
2019-06-27 19:22:35.925699+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:926
2019-06-27 19:22:35.925814+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-06-27 19:22:35.926058+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:35:926
2019-06-27 19:22:35.926264+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
運(yùn)行結(jié)果一：通過打印，我們知道
runloop的運(yùn)行狀態(tài)，分別經(jīng)歷了kCFRunLoopAfterWaiting，kCFRunLoopBeforeTimers，kCFRunLoopBeforeSources，kCFRunLoopBeforeWaiting，kCFRunLoopAfterWaiting，即runloop的運(yùn)行方式
運(yùn)行結(jié)果二
2019-06-27 19:22:36.031643+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=0,time:2019/06/27 07:22:36:032
2019-06-27 19:22:36.032004+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait timeoutCount = 0，time:2019/06/27 07:22:36:032
2019-06-27 19:22:36.032478+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=0,time:2019/06/27 07:22:36:032
2019-06-27 19:22:36.032681+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait timeoutCount = 0，time:2019/06/27 07:22:36:033
2019-06-27 19:22:36.084247+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:084
2019-06-27 19:22:36.084560+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 0,time:2019/06/27 07:22:36:084
2019-06-27 19:22:36.139575+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:139
2019-06-27 19:22:36.139918+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 1,time:2019/06/27 07:22:36:140
2019-06-27 19:22:36.191970+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:192
2019-06-27 19:22:36.192274+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 2,time:2019/06/27 07:22:36:192
2019-06-27 19:22:36.244942+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:245
2019-06-27 19:22:36.245238+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 3,time:2019/06/27 07:22:36:245
2019-06-27 19:22:36.295878+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:296
2019-06-27 19:22:36.296166+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 4,time:2019/06/27 07:22:36:296
2019-06-27 19:22:40.640854+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:40:641
2019-06-27 19:22:40.641015+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-06-27 19:22:40.641383+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019/06/27 07:22:40:641
2019-06-27 19:22:40.641608+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
2019-06-27 19:22:40.646402+0800 1129_PerformanceMonitor[66196:709130] ---------卡頓信息
Incident Identifier: B05FBB6C-274B-47FE-97FA-CCC2E78539FA
CrashReporter Key: TODO
Hardware Model: x86_64
Process: 1129_Performance [66196]
Path: /Users/cs/Library/Developer/CoreSimulator/Devices/2BAC277B-4BE9-4769-B3E0-12B8177803F9/data/Containers/Bundle/Application/95501A8D-58E3-4EEE-BB73-09BD40184682/1129_PerformanceMonitor.app/1129_PerformanceMonitor
Identifier: com.jm.PerformanceMonitor
Version: 1.0 (1)
Code Type: X86-64
Parent Process: debugserver [66197]
Date/Time: 2019-06-27 11:22:36 +0000
OS Version: Mac OS X 12.2 (18F132)
Report Version: 104
Exception Type: SIGTRAP
Exception Codes: TRAP_TRACE at 0x10e2c3f74
Crashed Thread: 5
Thread 0:
0 libsystem_kernel.dylib 0x0000000111235f32 __semwait_signal + 10
1 libsystem_c.dylib 0x0000000111019d24 usleep + 53
2 1129_PerformanceMonitor 0x000000010e2c4740 -[ViewController tableView:cellForRowAtIndexPath:] + 272
3 UIKitCore
接下來我們對(duì)該結(jié)果分段解釋說明
- 運(yùn)行結(jié)果2.1
2019-06-27 19:22:36.084560+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 0,time:2019/06/27 07:22:36:084
2019-06-27 19:22:36.139575+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:139
2019-06-27 19:22:36.139918+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 1,time:2019/06/27 07:22:36:140
2019-06-27 19:22:36.191970+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:192
2019-06-27 19:22:36.192274+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 2,time:2019/06/27 07:22:36:192
2019-06-27 19:22:36.244942+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:245
2019-06-27 19:22:36.245238+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 3,time:2019/06/27 07:22:36:245
2019-06-27 19:22:36.295878+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019/06/27 07:22:36:296
2019-06-27 19:22:36.296166+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 4,time:2019/06/27 07:22:36:296
運(yùn)行結(jié)果2.1：我們可以發(fā)現(xiàn)每次打印的時(shí)間間隔都超過了
50ms，也就是說達(dá)到了信號(hào)量的超時(shí)時(shí)間，則會(huì)進(jìn)入到if(st != 0)判斷中，即runloop的狀態(tài)長(zhǎng)時(shí)間沒有發(fā)生變更，又因?yàn)?code>activity = 4，即當(dāng)前runtoop的狀態(tài)為kCFRunLoopBeforeSources，停留在這個(gè)狀態(tài),表示在做很多事情，這個(gè)時(shí)候發(fā)生了卡頓現(xiàn)象，需要累計(jì)超時(shí)的次數(shù)timeoutCount。
- 運(yùn)行結(jié)果2.2
2019-06-27 19:22:40.646402+0800 1129_PerformanceMonitor[66196:709130] ---------卡頓信息
Incident Identifier: B05FBB6C-274B-47FE-97FA-CCC2E78539FA
CrashReporter Key: TODO
Hardware Model: x86_64
Process: 1129_Performance [66196]
Path: /Users/cs/Library/Developer/CoreSimulator/Devices/2BAC277B-4BE9-4769-B3E0-12B8177803F9/data/Containers/Bundle/Application/95501A8D-58E3-4EEE-BB73-09BD40184682/1129_PerformanceMonitor.app/1129_PerformanceMonitor
Identifier: com.jm.PerformanceMonitor
Version: 1.0 (1)
Code Type: X86-64
Parent Process: debugserver [66197]
Date/Time: 2019-06-27 11:22:36 +0000
OS Version: Mac OS X 12.2 (18F132)
Report Version: 104
Exception Type: SIGTRAP
Exception Codes: TRAP_TRACE at 0x10e2c3f74
Crashed Thread: 5
Thread 0:
0 libsystem_kernel.dylib 0x0000000111235f32 __semwait_signal + 10
1 libsystem_c.dylib 0x0000000111019d24 usleep + 53
2 1129_PerformanceMonitor 0x000000010e2c4740 -[ViewController tableView:cellForRowAtIndexPath:] + 272
3 UIKitCore
運(yùn)行結(jié)果 2.2：因?yàn)槌瑫r(shí)次數(shù)
timeoutCount已經(jīng)累計(jì)達(dá)到了5次，并且當(dāng)前runloop的狀態(tài)處于kCFRunLoopBeforeSources或kCFRunLoopAfterWaiting，即可判斷發(fā)生了卡頓，可以獲取當(dāng)前堆棧信息。
- 如何獲取卡頓的堆棧信息
// 收集Crash信息也可用于實(shí)時(shí)獲取各線程的調(diào)用堆棧
PLCrashReporterConfig *config = [[PLCrashReporterConfig alloc] initWithSignalHandlerType:PLCrashReporterSignalHandlerTypeBSD symbolicationStrategy:PLCrashReporterSymbolicationStrategyAll];
PLCrashReporter *crashReporter = [[PLCrashReporter alloc] initWithConfiguration:config];
NSData *data = [crashReporter generateLiveReport];
PLCrashReport *reporter = [[PLCrashReport alloc] initWithData:data error:NULL];
NSString *report = [PLCrashReportTextFormatter stringValueForCrashReport:reporter withTextFormat:PLCrashReportTextFormatiOS];
NSLog(@"---------卡頓信息\n%@\n--------------",report);
借助了一個(gè)第三方庫(kù)CrashReport，通過該庫(kù)，可以獲取當(dāng)前堆棧信息
圖解理解說明
WechatIMG617.jpeg
項(xiàng)目鏈接地址 - PerformanceMonitor
