实时卡顿检测-两种方案

2,693 阅读7分钟

1.什么原因导致了卡顿

  • 死锁
  • 抢锁
  • 大量的Ui绘制,复杂的UI,图文混排
  • 主线程大量IO、大量计算

2.相关知识补充 - 信号量

信号量就是一个资源计数器,对信号量有两个操作来达到互斥,分别是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有资源,排他访问资源。 这就是信号量来控制互斥的原理。

3.寻找卡顿切入点

RunLoop检测

监控卡顿,最直接就是找到主线程都在干些啥玩意儿.我们知道一个线程的消息事件处理都是依赖于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之后,也就是如果我们发现这两个时间内耗时太长,那么就可以判定出此时主线程卡顿。

iOS如何监控线程卡顿?

说一下QiLagMonitor中的大致实现思路。

  • 首先,创建一个观察者runLoopObserver,用于观察主线程的runloop状态。同时,还要创建一个信号量dispatchSemaphore,用于保证同步操作。

  • 其次,将观察者runLoopObserver添加到主线程runloop中观察。

  • 然后,开启一个子线程,并且在子线程中开启一个持续的loop来监控主线程runloop的状态。

  • 如果发现主线程runloop的状态卡在为BeforeSources或者AfterWaiting超过88毫秒时,即表明主线程当前卡顿。这时候,我们保存主线程当前的调用堆栈即可达成监控目的。

4.量化卡顿的程度

要监控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);之前。
获取kCFRunLoopBeforeSourceskCFRunLoopBeforeWaiting再到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);

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

子线程Ping

但是由于主线程的RunLoop在闲置时基本处于Before Waiting状态,这就导致了即便没有发生任何卡顿,这种检测方式也总能认定主线程处在卡顿状态。这套卡顿监控方案大致思路为:创建一个子线程通过信号量去ping主线程,因为ping的时候主线程肯定是在kCFRunLoopBeforeSources和kCFRunLoopAfterWaiting之间。每次检测时设置标记位为YES,然后派发任务到主线程中将标记位设置为NO。接着子线程沉睡超时阙值时长,判断标志位是否成功设置成NO,如果没有说明主线程发生了卡顿。ANREye中就是使用子线程Ping的方式监测卡顿的。

@interface PingThread : NSThread
......
@end

@implementation PingThread

- (void)main {
    [self pingMainThread];
}

- (void)pingMainThread {
    while (!self.cancelled) {
        @autoreleasepool {
            dispatch_async(dispatch_get_main_queue(), ^{
                [_lock unlock];
            });
            
            CFAbsoluteTime pingTime = CFAbsoluteTimeGetCurrent();
            NSArray *callSymbols = [StackBacktrace backtraceMainThread];
            [_lock lock];
            if (CFAbsoluteTimeGetCurrent() - pingTime >= _threshold) {
                ......
            }
            [NSThread sleepForTimeInterval: _interval];
        }
    }
}

@end

卡顿方法的栈信息

当我们得到卡顿的时间点,就要立即拿到卡顿的堆栈,有两种方式一种是遍历栈帧,实现原理我在iOS获取任意线程调用栈写的挺详细的,同时开源了代码RCBacktrace,另一种方式是通过Signal获取任意线程调用栈,实现原理我在通过Signal handling(信号处理)获取任意线程调用栈写了,代码在backtrace-swift,但这种方式在调试时比较麻烦,建议用第一种方式。

测试用例

写一个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;
}

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

二 FPS 监测

通常情况下,屏幕会保持60hz/s的刷新速度,每次刷新时会发出一个屏幕刷新信号CADisplayLink允许我们注册一个与刷新信号同步的回调处理。可以通过屏幕刷新机制来展示fps值:

方法一

@implementation ViewController {
    UILabel *_fpsLbe;
    
    CADisplayLink *_link;
    NSTimeInterval _lastTime;
    float _fps;
}

- (void)startMonitoring {
    if (_link) {
        [_link removeFromRunLoop:[NSRunLoop mainRunLoop] forMode:NSRunLoopCommonModes];
        [_link invalidate];
        _link = nil;
    }
    _link = [CADisplayLink displayLinkWithTarget:self selector:@selector(fpsDisplayLinkAction:)];
    [_link addToRunLoop:[NSRunLoop mainRunLoop] forMode:NSRunLoopCommonModes];
}

- (void)fpsDisplayLinkAction:(CADisplayLink *)link {
    if (_lastTime == 0) {
        _lastTime = link.timestamp;
        return;
    }
    
    self.count++;
    NSTimeInterval delta = link.timestamp - _lastTime;
    if (delta < 1) return;
    _lastTime = link.timestamp;
    _fps = _count / delta;
    NSLog(@"count = %d, delta = %f,_lastTime = %f, _fps = %.0f",_count, delta, _lastTime, _fps);
    self.count = 0;
    _fpsLbe.text = [NSString stringWithFormat:@"FPS:%.0f",_fps];
}

监听count值的改变

#pragma mark - observer

- (void)addObserver {
    [self addObserver:self forKeyPath:@"count" options:NSKeyValueObservingOptionNew | NSKeyValueObservingOptionOld context:nil];
}

- (void)observeValueForKeyPath:(NSString *)keyPath ofObject:(id)object change:(NSDictionary<NSKeyValueChangeKey,id> *)change context:(void *)context {
    NSLog(@"count new = %@, old = %@",[change valueForKey:@"new"], [change valueForKey:@"old"]);
}

1.通过打印,我们知道每次刷新时会发出一个屏幕刷新信号,则与刷新信号同步的回调方法`fpsDisplayLinkAction:`会调用,然后count加一。
2.每隔一秒,我们计算一次 `fps `值,用一个变量_lastTime记录上一次计算 fps 值的时间,然后将 count 的值除以时间间隔,就得到了 fps 的值,在将_lastTime重新赋值,_count置成零。
3.正常情况下,屏幕会保持60hz/s的刷新速度,所以1秒内`fpsDisplayLinkAction:`方法会调用60次。fps 计算的值为0,就不卡顿,流畅。
4.如果1秒内`fpsDisplayLinkAction:`只回调了50次,计算出来的fps就是 _count / delta(时间间隔) 。
方法二
- (void)startFpsMonitoring {
    _link = [CADisplayLink displayLinkWithTarget: self selector: @selector(displayFps:)];
    [_link addToRunLoop: [NSRunLoop mainRunLoop] forMode: NSRunLoopCommonModes];
}

- (void)displayFps: (CADisplayLink *)fpsDisplay {
    self.count++;
    CFAbsoluteTime threshold = CFAbsoluteTimeGetCurrent() - _lastTime;
    if (threshold >= 1.0) {
        _fps = (_count / threshold);
        _lastTime = CFAbsoluteTimeGetCurrent();
        _fpsLbe.text = [NSString stringWithFormat:@"FPS:%.0f",_fps];
        self.count = 0;
        NSLog(@"count = %d,_lastTime = %f, _fps = %.0f",_count, _lastTime, _fps);
    }
}

运行结果和方法一差不多。