ios - NSRunLoop : Is it really idle between kCFRunLoopBeforeWaiting & kCFRunLoopAfterWaiting?

Question

我对 NSRunLoop 循环很感兴趣，尤其是主运行循环。通过 CFRunLoopObserverRef，我们可以了解更多:

CFRunLoopObserverRef observerRef = CFRunLoopObserverCreateWithHandler(NULL, kCFRunLoopAllActivities, YES, 0, ^(CFRunLoopObserverRef observer, CFRunLoopActivity activity) {
    if (activity == kCFRunLoopBeforeTimers) {
        weakSelf.runloopId += 1;
    }
    NSLog(@"RunloopId : %lu, Activity : %ld, %lf\n", (unsigned long)weakSelf.runloopId, activity, [[NSDate date] timeIntervalSince1970]);
});
CFRunLoopAddObserver(CFRunLoopGetMain(), observerRef, kCFRunLoopCommonModes);

对于main runloop，我们可以忽略kCFRunLoopEntry & kCFRunLoopExit，关注kCFRunLoopBeforeTimers, kCFRunLoopBeforeSources, kCFRunLoopBeforeWaiting 和 kCFRunLoopAfterWaiting。

根据 The Run Loop Sequence of Events和 CFRunLoop.c ,

1. 主运行循环的一个循环从kCFRunLoopBeforeTimers开始，
2. 然后 kCFRunLoopBeforeSources,
3. 在上述两个事件之后，如果没有任何悬而未决的事情，就去 sleep ，

所以，在我看来，当主循环进入休眠状态时，它应该处于空闲状态。

正常等待状态

使用我上面的代码，当我打开应用程序(在模拟器中)并让它保持空闲状态时，runloop 事件回调将在控制台上打印日志:

2016-03-08 21:58:33.522 CaptureJitterDemo[25272:1312010] RunloopId : 156, Activity : 2, 1457445513.522846
2016-03-08 21:58:33.523 CaptureJitterDemo[25272:1312010] RunloopId : 156, Activity : 4, 1457445513.522985
2016-03-08 21:58:33.523 CaptureJitterDemo[25272:1312010] RunloopId : 156, Activity : 32, 1457445513.523144
2016-03-08 21:58:49.002 CaptureJitterDemo[25272:1312010] RunloopId : 156, Activity : 64, 1457445529.002502
2016-03-08 21:58:49.002 CaptureJitterDemo[25272:1312010] RunloopId : 157, Activity : 2, 1457445529.002820
2016-03-08 21:58:49.003 CaptureJitterDemo[25272:1312010] RunloopId : 157, Activity : 4, 1457445529.003044

Activity : 32 表示beforeWaiting，而Activity : 64 表示afterWaiting，两种状态之间主要调用堆栈如下所示:

无事可做，只是等待。

令人惊讶的等待状态

偶尔，我发现在 beforeWaiting 和 afterWaiting 之间可能会发生一些事情:

- (void)tableView:(UITableView *)tableView didSelectRowAtIndexPath:(NSIndexPath *)indexPath {
    NSLog(@"begin of url request... %lf\n", [[NSDate date] timeIntervalSince1970]);
    NSData *data = [NSData dataWithContentsOfURL:[NSURL URLWithString:@"https://c2.staticflickr.com/4/3771/9914251535_366536a515_h.jpg"]];
    if (data) {
        NSLog(@"end of url request : %lf\n", [[NSDate date] timeIntervalSince1970]);
    }
}

当我选择一行时，控制台打印:

2016-03-08 23:00:07.927 CaptureJitterDemo[25855:1334505] RunloopId : 27, Activity : 2, 1457449207.927184
2016-03-08 23:00:07.927 CaptureJitterDemo[25855:1334505] RunloopId : 27, Activity : 4, 1457449207.927399
2016-03-08 23:00:07.927 CaptureJitterDemo[25855:1334505] RunloopId : 27, Activity : 32, 1457449207.927624
2016-03-08 23:00:07.929 CaptureJitterDemo[25855:1334505] begin of url request... 1457449207.929021
2016-03-08 23:00:10.277 CaptureJitterDemo[25855:1334505] end of url request : 1457449210.276982
2016-03-08 23:00:10.278 CaptureJitterDemo[25855:1334505] RunloopId : 27, Activity : 64, 1457449210.278046
2016-03-08 23:00:10.278 CaptureJitterDemo[25855:1334505] RunloopId : 28, Activity : 2, 1457449210.278244
2016-03-08 23:00:10.278 CaptureJitterDemo[25855:1334505] RunloopId : 28, Activity : 4, 1457449210.278486
2016-03-08 23:00:10.278 CaptureJitterDemo[25855:1334505] RunloopId : 28, Activity : 32, 1457449210.278752

根据日志，在beforeWaiting和afterWaiting之间，应用完成了一个url请求任务。这让我很困惑。

起初我的误解

起初，我认为在主线程上同步url请求会导致主runloop进入waiting状态。但是后来发现app先进入了waiting状态，然后才出现url请求。

所以，现在出现的现象是主runloop进入waiting状态后，仍然可以在不唤醒自己的情况下进行同步url请求——开什么玩笑？

如果我将代码移动到viewDidAppear:

- (void)viewDidAppear:(BOOL)animated {
    [super viewDidAppear:animated];
    
    NSLog(@"begin of url request... %lf\n", [[NSDate date] timeIntervalSince1970]);
    NSData *data = [NSData dataWithContentsOfURL:[NSURL URLWithString:@"https://c2.staticflickr.com/4/3771/9914251535_366536a515_h.jpg"]];
    if (data) {
        NSLog(@"end of url request : %lf\n", [[NSDate date] timeIntervalSince1970]);
    }
}

控制台打印:

2016-03-08 23:42:25.616 CaptureJitterDemo[26268:1377354] RunloopId : 0, Activity : 1, 1457451745.616474
2016-03-08 23:42:25.617 CaptureJitterDemo[26268:1377354] RunloopId : 1, Activity : 2, 1457451745.617201
2016-03-08 23:42:25.617 CaptureJitterDemo[26268:1377354] RunloopId : 1, Activity : 4, 1457451745.617346
2016-03-08 23:42:25.618 CaptureJitterDemo[26268:1377354] begin of url request... 1457451745.618176
2016-03-08 23:42:27.832 CaptureJitterDemo[26268:1377354] end of url request : 1457451747.832428
2016-03-08 23:42:27.832 CaptureJitterDemo[26268:1377354] RunloopId : 2, Activity : 2, 1457451747.832818
2016-03-08 23:42:27.832 CaptureJitterDemo[26268:1377354] RunloopId : 2, Activity : 4, 

这似乎更容易接受。

我真正想做的事

我想在主运行循环上计算循环成本的时间，但不应该包括空闲时间。

循环意味着:

1. 如果 sleep 没有发生:kCFRunLoopBeforeTimers ->kCFRunLoopBeforeSources -> kCFRunLoopBeforeTimers;
2. 如果 sleep 发生:kCFRunLoopBeforeTimers -> kCFRunLoopBeforeSources ->kCFRunLoopBeforeWaiting -> kCFRunLoopAfterWaiting ->kCFRunLoopBeforeTimers;

对于 kCFRunLoopBeforeWaiting -> kCFRunLoopAfterWaiting 之间的时间成本:

1. 如果是正常等待状态，应该排除这个时间，因为它真的很闲；
2. else如果是令人惊讶的等待状态，应该包括时间，因为它确实完成了工作；

感谢您的帮助:)

Answer 1

查看令人惊讶的等待时间 堆栈跟踪，看起来 Core Animation 刷新是由于观察运行循环而发生的。我的猜测是它正在观察 kCFRunLoopBeforeWaiting 事件并最终触发 didSelectRow.. 作为结果。由于调用是阻塞的，因此运行循环会停留在该步骤(事件序列中的第 6 步)，直到发出信号量。

要实现你想做的事 - 为 kCFRunLoopBeforeWaiting 和 kCFRunLoopAfterWaiting 以及 CFRunLoopObserverCreateWithHandler 的第 4 个参数(顺序)创建一个单独的观察者分别传入LONG_MAX和0

此外，最好在 [[NSDate date] timeIntervalSince1970] 上使用 CACurrentMediaTime()，因为它是单调的。