当我的主线程阻塞时,如何获得断点/日志/增加可见性？

Question

在对UI响应的永无止境的追求中,我想更深入地了解主线程执行阻塞操作的情况.

我正在寻找某种"调试模式"或额外的代码,或钩子,或其他任何东西,我可以设置一个断点/日志/会被击中的东西,并允许我检查如果我的主线程"自愿"将会发生什么除了在runloop结束时空闲之外的I/O块(或者其他任何原因).

在过去,我使用runloop观察器查看了runloop循环挂钟的持续时间,这对于查看问题非常有价值,但是当你可以检查时,对于它正在做的事情了解它已经太晚了,因为你的代码已经在runloop的那个循环中运行了.

我意识到UIKit/AppKit执行的操作只是主线程,会导致I/O并导致主线程阻塞,所以在某种程度上,它是没有希望的(例如,访问粘贴板似乎是一个可能阻塞的,仅主线程的操作)但是有些东西总比没有好.

有人有什么好主意吗？看起来像是有用的东西.在理想情况下,当你的应用程序代码在runloop上处于活动状态时,你永远不会想要阻止主线程,这样的事情对于尽可能接近目标非常有帮助.

Answer 1

所以我本周末开始回答我自己的问题.据记载,这一努力变成了一件非常复杂的事情,就像肯德尔赫尔姆斯特特格伦所说的那样,大多数读这个问题的人应该只是用仪器搞砸了.对于人群中的受虐狂,请继续阅读!

最简单的方法是重申问题.这是我想出的:

我希望能够在syscalls/mach_msg_trap中花费很长时间,这些时间不是合法的空闲时间."合法空闲时间"定义为在mach_msg_trap中等待来自OS的下一个事件所花费的时间.

同样重要的是,我不关心需要很长时间的用户代码.使用Instruments的Time Profiler工具可以很容易地诊断和理解这个问题.我想特别了解封锁时间.虽然您也可以使用Time Profiler诊断阻塞的时间,但我发现它很难用于此目的.同样,系统跟踪仪器对于这样的调查也很有用,但是非常精细和复杂.我想要更简单的东西 - 更多地针对这个特定的任务.

从一开始就可以看出,这里选择的工具就是Dtrace.我开始用CFRunLoop的是射击观察员kCFRunLoopAfterWaiting和kCFRunLoopBeforeWaiting.对我的kCFRunLoopBeforeWaiting处理程序的调用将指示"合法空闲时间"的开始,并且kCFRunLoopAfterWaiting处理程序将向我发出合法等待已经结束的信号.我会使用Dtrace pid提供程序来捕获对这些函数的调用,以便将合法空闲从阻塞空闲中排序.

这种方法让我开始,但最终证明是有缺陷的.最大的问题是许多AppKit操作是同步的,因为它们阻止了UI中的事件处理,但实际上在调用堆栈中将RunLoop旋转得更低.RunLoop的这些旋转不是"合法的"空闲时间(出于我的目的),因为在此期间用户无法与UI交互.它们很有价值,可以肯定 - 想象一下后台线程上的runloop正在观看一堆面向RunLoop的I/O--但是当主线程发生这种情况时,UI仍然被阻止.例如,我将以下代码放入IBAction并从按钮触发:

NSMutableURLRequest *req = [NSMutableURLRequest requestWithURL: [NSURL URLWithString: @"http://www.google.com/"] 
                                                   cachePolicy: NSURLRequestReloadIgnoringCacheData
                                               timeoutInterval: 60.0];    
NSURLResponse* response = nil;
NSError* err = nil;
[NSURLConnection sendSynchronousRequest: req returningResponse: &response error: &err];

该代码不会阻止RunLoop旋转 - AppKit会在sendSynchronousRequest:...调用内为您旋转它- 但它确实阻止用户在返回之前与UI交互.这不是我认为的"合法闲置",所以我需要一种方法来解决哪些空闲.(这种CFRunLoopObserver方法也存在缺陷,因为它需要对代码进行更改,而我的最终解决方案却没有.)

我决定将UI /主线程建模为状态机.它始终处于三种状态之一:LEGIT_IDLE,RUNNING或BLOCKED,并且在程序执行时将在这些状态之间来回转换.我需要提出Dtrace探针,这些探针可以让我捕捉(并因此测量)那些转变.我实施的最终状态机比这三个状态要复杂得多,但那是20,000英尺的视图.

如上所述,从坏空闲中挑选合法空闲并不简单,因为两种情况最终都在mach_msg_trap()和__CFRunLoopRun.我在调用堆栈中找不到一个可以用来可靠地区分的简单工件; 似乎对一个函数的简单探测对我没有帮助.我最终使用调试器来查看合法空闲与坏空闲的各种实例的堆栈状态.我确定在合法闲置期间,我(看似可靠)看到这样的调用堆栈:

#0  in mach_msg
#1  in __CFRunLoopServiceMachPort
#2  in __CFRunLoopRun
#3  in CFRunLoopRunSpecific
#4  in RunCurrentEventLoopInMode
#5  in ReceiveNextEventCommon
#6  in BlockUntilNextEventMatchingListInMode
#7  in _DPSNextEvent
#8  in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]
#9  in -[NSApplication run]
#10 in NSApplicationMain
#11 in main

因此,我努力设置一堆嵌套/链式pid探测器,这些探测器将在我到达并随后离开此状态时建立.遗憾的是,无论出于何种原因,Dtrace的pid提供程序似乎无法普遍地探测所有任意符号的入口和返回.具体来说,我不能让探头上pid000:*:__CFRunLoopServiceMachPort:return或在pid000:*:_DPSNextEvent:return工作.细节并不重要,但通过观察其他各种事情并跟踪某些状态,我能够在进入时建立(再次,看似可靠)并离开合法的闲置状态.

然后我必须确定探测器来说明RUNNING和BLOCKED之间的区别.这有点容易.最后,我选择考虑使用BSD系统调用(使用Dtrace的系统调用探测)并调用mach_msg_trap()(使用pid探测)在合法空闲期间不会发生阻塞.(我确实看过Dtrace的mach_trap探测器,但它似乎没有做我想要的,所以我又回到了使用pid探测器.)

最初,我在Dtrace sched提供程序上做了一些额外的工作来实际测量实际阻塞时间(即我的线程被调度程序暂停的时间),但这增加了相当大的复杂性,我最后想到自己,"如果我是在内核中,如果线程实际上是睡着了我该怎么办呢？它对用户来说都是一样的:它被阻止了." 所以最后的方法只是测量所有时间(syscalls || mach_msg_trap()) && !legit_idle并调用阻塞时间.

此时,捕获长持续时间的单个内核调用(例如调用sleep(5)例如)变得微不足道.但是,更常见的是,UI线程延迟来自于内核多次调用时累积的许多小延迟(想想数百次调用read()或select()),所以我认为在转发时调用SOME调用堆栈也是可取的.mach_msg_trap事件循环的单次传递中的系统调用或时间总量超过某个阈值.我最终设置了各种计时器并记录在每个状态中花费的累计时间,确定状态机中的各种状态,并在我们碰巧转换到BLOCKED状态时转储警报,并且已超过某个阈值.这种方法显然会产生可能被误解的数据,或者可能是一个完全红色的鲱鱼(即一些随机的,相对快速的系统调用,恰好会使我们超过警报阈值),但我觉得它总比没有好.

最后,Dtrace脚本最终将状态机保存在D变量中,并使用所描述的探针跟踪状态之间的转换,并使我有机会在状态机转换状态时执行操作(如打印警报),在某些条件下.我用一个人为的样本应用程序玩了一下,它做了一堆磁盘I/O,网络I/O和调用sleep(),并且能够捕获所有这三种情况,而不会分散与合法等待有关的数据.这正是我想要的.

这个解决方案显然非常脆弱,几乎在所有方面都非常糟糕.:)它对我或其他任何人可能有用也可能没有用,但这是一个有趣的练习,所以我想我会分享这个故事,以及由此产生的Dtrace脚本.也许别人会觉得它很有用.我也必须承认自己是n00b写作Dtrace脚本的亲戚,所以我确信我做了一百万件事.请享用!

它太大了,无法在线发布,所以它很友好地由@Catfish_Man在这里托管:MainThreadBlocking.d