我怎么能得到断点/日志/增加可见性时,我的主线程阻塞



在对UI响应性永无止境的追求中,我希望对主线程执行阻塞操作的情况有更多的了解。

我正在寻找某种"调试模式"或额外的代码,或钩子,或其他什么,我可以设置一个断点/日志/什么东西,将被命中,并允许我检查发生了什么,如果我的主线程"自愿"阻塞I/O(或任何原因,真的),而不是在运行循环结束时空闲。

在过去,我使用一个运行循环观察者来查看运行循环的时钟持续时间,这对于发现问题很有价值,但是当你可以检查的时候,要想知道它在做什么已经太晚了,因为你的代码已经完成了运行循环的那个周期。

我意识到UIKit/AppKit执行的操作是主线程只读的,会导致I/O并导致主线程阻塞,因此,在某种程度上,这是无望的(例如,访问粘贴板似乎是一个潜在的阻塞,主线程只读操作),但总比没有好。

谁有什么好主意?好像是有用的东西。在理想的情况下,当你的应用程序代码在运行循环中处于活动状态时,你永远不想阻塞主线程,而这样的东西将非常有助于尽可能接近这个目标。

所以这个周末我开始回答我自己的问题。根据记录,这种努力变得相当复杂,所以就像Kendall Helmstetter Glen建议的那样,大多数读到这个问题的人可能只需要用Instruments就可以了。对于人群中的受虐狂,请继续阅读!

以重述问题开始是最容易的。这是我想到的:

我想被提醒长时间花在系统调用/mach_msg_trap不是合法的空闲时间。"合法"空闲时间"定义为mach_msg_trap中等待的时间操作系统的下一个事件。

同样重要的是,我不关心花费很长时间的用户代码。使用Instruments的Time Profiler工具,这个问题很容易诊断和理解。我特别想知道被封锁的时间。虽然你也可以用time Profiler来诊断阻塞的时间,但我发现它很难用于这个目的。同样地,System Trace Instrument对于这类调查也很有用,但是它的粒度非常细,而且非常复杂。我想要一些更简单的东西——更有针对性的具体任务。

从一开始就很明显,这里选择的工具是Dtrace。我开始使用一个CFRunLoop观察者在kCFRunLoopAfterWaitingkCFRunLoopBeforeWaiting上开火。对kCFRunLoopBeforeWaiting处理程序的调用将表示"合法空闲时间"的开始,而kCFRunLoopAfterWaiting处理程序将向我发出合法等待已经结束的信号。我将使用Dtrace pid提供程序来捕获对这些函数的调用,作为对合法空闲和阻塞空闲进行分类的一种方法。

这个方法让我开始,但最终证明是有缺陷的。最大的问题是,许多AppKit操作是同步的,因为它们阻塞了UI中的事件处理,但实际上旋转了调用堆栈中较低的RunLoop。这些RunLoop的旋转不是"合法的"空闲时间(就我的目的而言),因为用户在那段时间不能与UI交互。可以肯定的是,它们是有价值的——想象一下后台线程上的运行循环在监视一堆面向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:returnpid000:*:_DPSNextEvent:return上的探针工作。细节并不重要,但通过观察各种其他情况,并跟踪某些状态,我能够确定(再次,看起来可靠)何时进入和离开合法的空闲状态。

然后,我必须确定用于区分RUNNING和BLOCKED的探针。这就简单多了。最后,我选择考虑在合法空闲期间不发生的BSD系统调用(使用Dtrace的系统调用探针)和对mach_msg_trap()的调用(使用pid探针)。(我确实查看了Dtrace的mach_trap探测,但它似乎没有做我想做的事情,所以我又回到使用pid探测。)

最初,我使用Dtrace调度提供程序做了一些额外的工作来实际测量实际阻塞时间(即我的线程被调度器挂起的时间),但这增加了相当大的复杂性,我最终对自己说,"如果我在内核中,我怎么关心线程是否实际上处于睡眠状态?对用户来说都是一样的:它被屏蔽了。"所以最后一种方法只是测量(syscalls || mach_msg_trap()) && !legit_idle中的所有时间,并将其称为阻塞时间。

在这一点上,捕获长时间的单个内核调用(例如对sleep(5)的调用)变得微不足道。然而,更多时候UI线程延迟来自多次调用内核累积的许多小延迟(想想对read()或select()的数百次调用),所以我认为,当事件循环的单次传递中的系统调用或mach_msg_trap时间总量超过某个阈值时,转储一些调用堆栈也是可取的。最后,我设置了各种计时器,并记录了在每个状态下所花费的累积时间,将范围限定为状态机中的各种状态,并在我们碰巧从BLOCKED状态过渡到超过某个阈值时转储警报。这种方法显然会产生容易被误解的数据,或者可能会完全转移注意力(例如,一些随机的、相对快速的系统调用恰好将我们推过警报阈值),但我觉得这总比没有好。

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

这个解决方案显然很脆弱,非常糟糕在几乎所有方面。:)它可能对我或其他任何人有用,也可能没用,但这是一个有趣的练习,所以我想我应该分享这个故事,以及由此产生的Dtrace脚本。也许其他人会发现它很有用。我还必须承认,在编写Dtrace脚本方面,我是一个相对的n00b,所以我确信我做错了一百万件事。享受吧!

它太大了,不能在网上发布,所以它由@Catfish_Man在这里托管:MainThreadBlocking.d

这确实是Time Profiler仪器的工作。我相信你可以看到每个线程的代码中花费的时间,所以你应该去看看哪些代码需要一些时间来执行,并得到潜在阻塞UI的答案。

最新更新