iOS监控卡顿方案

前言

在移动设备上开发软件,性能一直是我们最为关心的话题之一,我们作为程序员除了需要努力提高代码质量之外,及时发现和监控软件中那些造成性能低下的”罪魁祸首”也是我们神圣的职责。

众所周知,iOS平台因为UIKit本身的特性,需要将所有的UI操作都放在主线程执行,所以也造成不少程序员都习惯将一些线程安全性不确定的逻辑,以及其它线程结束后的汇总工作等等放到了主线,所以主线程中包含的这些大量计算、IO、绘制都有可能造成卡顿。

在Xcode中已经集成了非常方便的调试工具Instruments,它可以帮助我们在开发测试阶段分析软件运行的性能消耗,但一款软件经过测试流程和实验室分析肯定是不够的,在正式环境中由大量用户在使用过程中监控、分析到的数据更能解决一些隐藏的问题。

什么原因导致了卡顿
  • 死锁
  • 抢锁
  • 大量的Ui绘制,复杂的UI，图文混排
  • 主线程大量IO、大量计算
相关知识补充 - 信号量

信号量就是一个资源计数器，对信号量有两个操作来达到互斥，分别是P和V操作。 一般情况是这样进行临界访问或互斥访问的： 设信号量值为1， 当一个进程1运行时，使用资源，进行P操作，即对信号量值减1，也就是资源数少了1个，这时信号量值为0。

系统中规定当信号量值为0时，必须等待，直到信号量值不为零才能继续操作。 这时如果进程2想要运行，那么也必须进行P操作，但是此时信号量为0，所以无法减1，即不能P操作，也就阻塞，这样就到到了进程1排他访问。

当进程1运行结束后，释放资源，进行V操作。资源数重新加1，这时信号量的值变为1. 这时进程2发现资源数不为0，信号量能进行P操作了，立即执行P操作。信号量值又变为0，这时进程2有资源，排他访问资源。 这就是信号量来控制互斥的原理。

卡顿困难点

  • 不易重现
    可能是特定用户的手机上才有问题，由于种种原因这个手机不能拿来调试；也有可能是特定的时机才会出问题，过后就不能重现了（例如线程抢锁）。

  • 操作路径长，日志无法准确打点
    对于这些界面卡顿反馈，通常我们拿用户日志作用不大，增加日志点也用处不大。只能不断重试希望能够重现出来，或者埋头代码逻辑中试图能找的蛛丝马迹

寻找卡顿切入点

监控卡顿,最直接就是找到主线程都在干些啥玩意儿.我们知道一个线程的消息事件处理都是依赖于NSRunLoop来驱动,所以要知道线程正在调用什么方法,就需要从NSRunLoop来入手.CFRunLoop的代码是开源,可以在此处查阅到 CFRunLoop.c 源代码

其中核心方法CFRunLoopRun简化后的主要逻辑大概是这样的:

/// 1\. 通知Observers，即将进入RunLoop
    /// 此处有Observer会创建AutoreleasePool: _objc_autoreleasePoolPush();
    __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopEntry);
    do {

        /// 2\. 通知 Observers: 即将触发 Timer 回调。
        __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopBeforeTimers);
        /// 3\. 通知 Observers: 即将触发 Source (非基于port的,Source0) 回调。
        __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__(kCFRunLoopBeforeSources);
        __CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__(block);

        /// 4\. 触发 Source0 (非基于port的) 回调。
        __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__(source0);

        /// 5\. GCD处理main block
        __CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__(block);

        /// 6\. 通知Observers，即将进入休眠
        /// 此处有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唤醒的，回调Timer
        __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__(timer);

        /// 9\. 如果是被dispatch唤醒的，执行所有调用 dispatch_async 等方法放入main queue 的 block
        __CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__(dispatched_block);

        /// 9\. 如果如果Runloop是被 Source1 (基于port的) 的事件唤醒了，处理这个事件
        __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);
}

不难发现NSRunLoop调用方法主要就是在kCFRunLoopBeforeSources和kCFRunLoopBeforeWaiting之间,还有kCFRunLoopAfterWaiting之后,也就是如果我们发现这两个时间内耗时太长,那么就可以判定出此时主线程卡顿。

量化卡顿的程度

要监控NSRunLoop的状态,我们需要使用到CFRunLoopObserverRef,通过它可以实时获得这些状态值的变化,具体的使用如下:

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的状态就可以知道是否有卡顿的情况。

实现思路：只需要另外再开启一个线程,实时计算这两个状态区域之间的耗时是否到达某个阀值,便能揪出这些性能杀手。

  • 监听runloop状态变化
// 就是runloop有一个状态改变 就记录一下
static void runLoopObserverCallBack(CFRunLoopObserverRef observer, CFRunLoopActivity activity, void *info) {
    BGPerformanceMonitor *monitor = (__bridge BGPerformanceMonitor*)info;

    // 记录状态值
    monitor->activity = activity;

    // 发送信号
    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),    // 进入RunLoop循环(这里其实还没进入)
//        kCFRunLoopBeforeTimers = (1UL << 1),  // RunLoop 要处理timer了
//        kCFRunLoopBeforeSources = (1UL << 2), // RunLoop 要处理source了
//        kCFRunLoopBeforeWaiting = (1UL << 5), // RunLoop要休眠了
//        kCFRunLoopAfterWaiting = (1UL << 6),   // RunLoop醒了
//        kCFRunLoopExit = (1UL << 7),           // RunLoop退出（和kCFRunLoopEntry对应）
//        kCFRunLoopAllActivities = 0x0FFFFFFFU
//    };

    if (activity == kCFRunLoopEntry) {  // 即将进入RunLoop
        NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopEntry");
    } else if (activity == kCFRunLoopBeforeTimers) {    // 即将处理Timer
        NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopBeforeTimers");
    } else if (activity == kCFRunLoopBeforeSources) {   // 即将处理Source
        NSLog(@"runLoopObserverCallBack - %@",@"kCFRunLoopBeforeSources");
    } else if (activity == kCFRunLoopBeforeWaiting) {   //即将进入休眠
        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 监听
// 开始监听
- (void)startMonitor {
    if (observer) {
        return;
    }

    // 创建信号
    semaphore = dispatch_semaphore_create(0);
    NSLog(@"dispatch_semaphore_create:%@",[BGPerformanceMonitor getCurTime]);

    // 注册RunLoop状态观察
    CFRunLoopObserverContext context = {0,(__bridge void*)self,NULL,NULL};
    //创建Run loop observer对象
    //第一个参数用于分配observer对象的内存
    //第二个参数用以设置observer所要关注的事件，详见回调函数myRunLoopObserver中注释
    //第三个参数用于标识该observer是在第一次进入run loop时执行还是每次进入run loop处理时均执行
    //第四个参数用于设置该observer的优先级
    //第五个参数用于设置该observer的回调函数
    //第六个参数用于设置该observer的运行环境
    observer = CFRunLoopObserverCreate(kCFAllocatorDefault,
                                       kCFRunLoopAllActivities,
                                       YES,
                                       0,
                                       &runLoopObserverCallBack,
                                       &context);
    CFRunLoopAddObserver(CFRunLoopGetMain(), observer, kCFRunLoopCommonModes);

    // 在子线程监控时长
    dispatch_async(dispatch_get_global_queue(0, 0), ^{
        while (YES) {   // 有信号的话 就查询当前runloop的状态
            // 假定连续5次超时50ms认为卡顿(当然也包含了单次超时250ms)
            // 因为下面 runloop 状态改变回调方法runLoopObserverCallBack中会将信号量递增 1,所以每次 runloop 状态改变后,下面的语句都会执行一次
            // 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) {  // 信号量超时了 - 即 runloop 的状态长时间没有发生变更,长期处于某一个状态下
                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的状态就可以知道是否有卡顿的情况。
                // kCFRunLoopBeforeSources:停留在这个状态,表示在做很多事情
                if (activity == kCFRunLoopBeforeSources || activity == kCFRunLoopAfterWaiting) {    // 发生卡顿,记录卡顿次数
                    if (++timeoutCount < 5) {
                        continue;   // 不足 5 次,直接 continue 当次循环,不将timeoutCount置为0
                    }

                    // 收集Crash信息也可用于实时获取各线程的调用堆栈
                    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;
        }
    });
}
记录卡顿的函数调用

监控到了卡顿现场,当然下一步便是记录此时的函数调用信息,此处可以使用一个第三方Crash收集组件PLCrashReporter,它不仅可以收集Crash信息也可用于实时获取各线程的调用堆栈,使用示例如下:

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);

当检测到卡顿时,抓取堆栈信息,然后在客户端做一些过滤处理,便可以上报到服务器,通过收集一定量的卡顿数据后经过分析便能准确定位需要优化的逻辑,至此这个实时卡顿监控就大功告成了!

测试用例

写一个tableView视图，上下拖动，并人为设置卡顿(休眠)

- (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 = @"我在做复杂的事情，需要一些时间";
    } else {
        text = [NSString stringWithFormat:@"cell - %ld",indexPath.row];
    }

    cell.textLabel.text = text;

    return cell;
}
运行结果一
2019-12-20 19:22:35.898214+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopAfterWaiting
2019-12-20 19:22:35.899001+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:899
2019-12-20 19:22:35.899395+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-12-20 19:22:35.900216+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:900
2019-12-20 19:22:35.900425+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
2019-12-20 19:22:35.903171+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:903
2019-12-20 19:22:35.903317+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-12-20 19:22:35.903563+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:903
2019-12-20 19:22:35.903722+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
2019-12-20 19:22:35.904127+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:904
2019-12-20 19:22:35.904372+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeWaiting
2019-12-20 19:22:35.901860+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait timeoutCount = 0，time:2019-12-20 11:22:35:898
2019-12-20 19:22:35.906158+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=0,time:2019-12-20 11:22:35:906
2019-12-20 19:22:35.914693+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:914
2019-12-20 19:22:35.915027+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopAfterWaiting
2019-12-20 19:22:35.917535+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:916
2019-12-20 19:22:35.918352+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-12-20 19:22:35.919467+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:919
2019-12-20 19:22:35.919853+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
2019-12-20 19:22:35.920694+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:920
2019-12-20 19:22:35.921004+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeWaiting
2019-12-20 19:22:35.925240+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:925
2019-12-20 19:22:35.925425+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopAfterWaiting
2019-12-20 19:22:35.925699+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:926
2019-12-20 19:22:35.925814+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-12-20 19:22:35.926058+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:35:926
2019-12-20 19:22:35.926264+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources

运行结果一：通过打印，我们知道runloop的运行状态，分别经历了kCFRunLoopAfterWaiting，kCFRunLoopBeforeTimers，kCFRunLoopBeforeSources，kCFRunLoopBeforeWaiting，kCFRunLoopAfterWaiting，即runloop的运行方式

运行结果二
2019-12-20 19:22:36.031643+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=0,time:2019-12-20 11:22:36:032
2019-12-20 19:22:36.032004+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait timeoutCount = 0，time:2019/06/27 11:22:36:032
2019-12-20 19:22:36.032478+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=0,time:2019-12-20 11:22:36:032
2019-12-20 19:22:36.032681+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait timeoutCount = 0，time:2019/06/27 11:22:36:033
2019-12-20 19:22:36.084247+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:084
2019-12-20 19:22:36.084560+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 0,time:2019-12-20 11:22:36:084
2019-12-20 19:22:36.139575+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:139
2019-12-20 19:22:36.139918+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 1,time:2019-12-20 11:22:36:140
2019-12-20 19:22:36.191970+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:192
2019-12-20 19:22:36.192274+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 2,time:2019-12-20 11:22:36:192
2019-12-20 19:22:36.244942+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:245
2019-12-20 19:22:36.245238+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 3,time:2019-12-20 11:22:36:245
2019-12-20 19:22:36.295878+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:296
2019-12-20 19:22:36.296166+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 4,time:2019-12-20 11:22:36:296
2019-12-20 19:22:40.640854+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:40:641
2019-12-20 19:22:40.641015+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeTimers
2019-12-20 19:22:40.641383+0800 1129_PerformanceMonitor[66196:708905] dispatch_semaphore_signal:st=0,time:2019-12-20 11:22:40:641
2019-12-20 19:22:40.641608+0800 1129_PerformanceMonitor[66196:708905] runLoopObserverCallBack - kCFRunLoopBeforeSources
2019-12-20 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-12-20 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

接下来我们对该结果分段解释说明

  • 运行结果2.1
2019-12-20 19:22:36.084560+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 0,time:2019-12-20 11:22:36:084
2019-12-20 19:22:36.139575+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:139
2019-12-20 19:22:36.139918+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 1,time:2019-12-20 11:22:36:140
2019-12-20 19:22:36.191970+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:192
2019-12-20 19:22:36.192274+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 2,time:2019-12-20 11:22:36:192
2019-12-20 19:22:36.244942+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:245
2019-12-20 19:22:36.245238+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 3,time:2019-12-20 11:22:36:245
2019-12-20 19:22:36.295878+0800 1129_PerformanceMonitor[66196:709130] dispatch_semaphore_wait:st=49,time:2019-12-20 11:22:36:296
2019-12-20 19:22:36.296166+0800 1129_PerformanceMonitor[66196:709130] st = 49,activity = 4,timeoutCount = 4,time:2019-12-20 11:22:36:296

运行结果2.1：我们可以发现每次打印的时间间隔都超过了50ms，也就是说达到了信号量的超时时间，则会进入到if(st != 0)判断中，即runloop的状态长时间没有发生变更，又因为activity = 4，即当前runtoop的状态为kCFRunLoopBeforeSources，停留在这个状态,表示在做很多事情，这个时候发生了卡顿现象，需要累计超时的次数timeoutCount。

  • 运行结果2.2
2019-12-20 12: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-12-20 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

运行结果 2.2：因为超时次数timeoutCount已经累计达到了5次，并且当前runloop的状态处于kCFRunLoopBeforeSources或kCFRunLoopAfterWaiting，即可判断发生了卡顿，可以获取当前堆栈信息。

  • 如何获取卡顿的堆栈信息
// 收集Crash信息也可用于实时获取各线程的调用堆栈
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);

借助了一个第三方库CrashReport，通过该库，可以获取当前堆栈信息

最后编辑于 ：
©著作权归作者所有,转载或内容合作请联系作者
禁止转载，如需转载请通过简信或评论联系作者。
  • 人面猴
    序言：七十年代末，一起剥皮案震惊了整个滨河市，随后出现的几起案子，更是在滨河造成了极大的恐慌，老刑警刘岩，带你破解...
    沈念sama阅读 203,271评论 5赞 476
  • 死咒
    序言：滨河连续发生了三起死亡事件，死亡现场离奇诡异，居然都是意外死亡，警方通过查阅死者的电脑和手机，发现死者居然都...
    沈念sama阅读 85,275评论 2赞 380
  • 救了他两次的神仙让他今天三更去死
    文/潘晓璐 我一进店门，熙熙楼的掌柜王于贵愁眉苦脸地迎上来，“玉大人，你说我怎么就摊上这事。” “怎么了？”我有些...
    开封第一讲书人阅读 150,151评论 0赞 336
  • 道士缉凶录：失踪的卖姜人
    文/不坏的土叔 我叫张陵，是天一观的道长。 经常有香客问我，道长，这世上最难降的妖魔是什么？ 我笑而不...
    开封第一讲书人阅读 54,550评论 1赞 273
  • 港岛之恋（遗憾婚礼）
    正文 为了忘掉前任，我火速办了婚礼，结果婚礼上，老公的妹妹穿的比我还像新娘。我一直安慰自己，他们只是感情好，可当我...
    茶点故事阅读 63,553评论 5赞 365
  • 恶毒庶女顶嫁案：这布局不是一般人想出来的
    文/花漫 我一把揭开白布。 她就那样静静地躺着，像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上，一...
    开封第一讲书人阅读 48,559评论 1赞 281
  • 城市分裂传说
    那天，我揣着相机与录音，去河边找鬼。 笑死，一个胖子当着我的面吹牛，可吹牛的内容都是我干的。 我是一名探鬼主播，决...
    沈念sama阅读 37,924评论 3赞 395
  • 双鸳鸯连环套：你想象不到人心有多黑
    文/苍兰香墨 我猛地睁开眼，长吁一口气：“原来是场噩梦啊……” “哼！你这毒妇竟也来了？” 一声冷哼从身侧响起，我...
    开封第一讲书人阅读 36,580评论 0赞 257
  • 万荣杀人案实录
    序言：老挝万荣一对情侣失踪，失踪者是张志新（化名）和其女友刘颖，没想到半个月后，有当地人在树林里发现了一具尸体，经...
    沈念sama阅读 40,826评论 1赞 297
  • 护林员之死
    正文 独居荒郊野岭守林人离奇死亡，尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,578评论 2赞 320
  • 白月光启示录
    正文 我和宋清朗相恋三年，在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,661评论 1赞 329
  • 活死人
    序言：一个原本活蹦乱跳的男人离奇死亡，死状恐怖，灵堂内的尸体忽然破棺而出，到底是诈尸还是另有隐情，我是刑警宁泽，带...
    沈念sama阅读 33,363评论 4赞 318
  • 日本核电站爆炸内幕
    正文 年R本政府宣布，位于F岛的核电站，受9级特大地震影响，放射性物质发生泄漏。R本人自食恶果不足惜，却给世界环境...
    茶点故事阅读 38,940评论 3赞 307
  • 男人毒药：我在死后第九天来索命
    文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹，春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,926评论 0赞 19
  • 一桩弑父案，背后竟有这般阴谋
    文/苍兰香墨 我抬头看了看天上的太阳。三九已至，却和暖如春，着一层夹袄步出监牢的瞬间，已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,156评论 1赞 259
  • 情欲美人皮
    我被黑心中介骗来泰国打工， 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留，地道东北人。 一个月前我还...
    沈念sama阅读 42,872评论 2赞 349
  • 代替公主和亲
    正文 我出身青楼，却偏偏与公主长得像，于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子，可洞房花烛夜当晚...
    茶点故事阅读 42,391评论 2赞 342