7034a02775a25cc002612246b449d417
开始使用 Instrument

WWDC 2019 Session 411 Getting Started with Instruments

该 session 介绍了如何使用 Instruments 来衡量 app 的运行表现,通过它来找到 app 性能瓶颈并进行相应优化,通过 Demo 演示了如何使用 time profilersignposts 这两个工具来观察 app 的详细运行情况。
该 session 主要分为三个部分 :

  • Instrument 简介
  • 使用 Time Profiler 分析应用
  • 使用 Signpost

Instrument 简介

Instruments 是一个强大的性能分析和测试工具,它可以帮助开发者分析 app 的运行状况从而优化其性能。它被内置于 Xcode 中,但也可以作为一个独立 app 来使用,并且可以用于多平台(MacOS,iOS,tvOS,watchOS)。

打开 Instruments 面板, 可以看到里面有一系列的模板,本 session 着重介绍了 Time Profiler 模板的使用。
Time Profiler 可以用来检测应用的 cpu 使用情况,它会按照一定的时间间隔来追踪每一条线程和每个 cpu 核心的堆栈信息。

除了 Time Profile 外,Instruments 还提供了一系列好用的调试工具,比如 Core Animation 可以用来查看界面的离屏渲染、光栅化等;AllocationsLeaks 可以用来检查应用内存相关问题。网上有很多相关资料,这里就不再赘述了。

界面

左上角高亮区域是 profiling control (录制和暂停键) 以及 target area,通过 profiling control, 可以控制数据收集操作的开始、暂停和停止。通过target area,可以选择运行设备以及想要分析的应用。

使用 Instrument 会占用系统资源,为了使它对 app 的影响最小化,Instrument 提供了一种名为最后几秒模式(Last Few Seconds Mode)也称作窗口模式(Windowed Mode)的特性。在窗口模式下, Instrument 在记录结束前不会分析或者显示结果,并且它会忽略除最后几秒外所记录的所有事件。这种模式适用于开始记录后,遇到问题时就停止记录的情况。一部分 Instrument 模板默认使用这种模式,因为它们会在极短的时间内记录大量的数据。

当一次 time profiler 结束后,显示结果类似下图。窗口上方的高亮部分被称为 Track Viewer。其中的每行被称作一个 TrackTrack 显示的是某种事件来源下的追踪数据,例如进程、线程、cpu等。一次 Instrument 记录可能会包含大量的 track

第二行的 Points of interest 显示的是开发者所关注区域的信息。 可以通过一些 API,例如 signpost 来标记出那些你想要关注的重点区域。关于这点的具体内容下文还会提到。

窗口的左下部分被称为 Detail View,在这里可以查看选中 Track 的详细记录数据。

Detail View 的右侧是 Extended Detail View, 它会根据使用的 Instrument 模板提供相应地更加丰富的信息,在本例中,使用的是 time profiler,所以这里显示的是 Heaviest Stack Trace

通过鼠标可以选中关注的区域,选中之后,Detail ViewExtended Detail View 也会更新来专注于选中的数据。

有关 Instrument 界面内容的更详细介绍,可以参见苹果官方文档 Instruments Help

使用 Time Profiler

在 WWDC 2018,苹果展示了一款名为 Solar System 的 Mac 应用。它支持点击、拖拽、缩放等多种手势来查看太阳系行星的运行轨迹,用户反映当他们使用 Command + R 命令刷新 app 数据时,页面会卡死并出现旋转等待图标(我们俗称的小菊花),在本 session 中,苹果工程师把它作为 demo 来演示如何通过 Instrument 来定位并修复该问题。

打开 Instrument,选择 time profiler 模板并开启录制,在一顿点击、移动、缩放、Command + R 操作之后,instrument 记录了一系列数据。在 cpu 使用率的高峰值区域,出现了一个红色的标签显示着 spinning 。在 Instrument 中出现 spinning 代表主线程被阻塞了。

查看 Main Thread 的记录数据,可以看到有一段高峰值,选中该区域,窗口下部的 Detail View 会更新并显示该段时间的记录详情。

由于 Detail View 展示的信息太多,很难定位问题。我们可以查看右侧的 Expended Detail View 所显示的 Heaviest Stack TraceHeaviest Stack Trace 会展示这段时间内被频繁调用的函数。在这里,显示灰色的是系统框架提供的函数,白色的是进程的函数。

可以看到一个名为 scheduleParsingTask 的函数, 这个函数在主线程上执行了一些数据解析的操作,导致了主线程的阻塞。

为了修复这个bug,需要创建一个 parsingQueue,并把数据解析操作放入该 queue, 如下图所示

再次运行 Instrument,在 app 上执行相同的操作后不会再发生卡死的现象。通过查看主线程上的记录数据,可以发现主线程上的 cpu 使用率维持在一个稳定且较低的状态,该bug已经被解决了。

Profiling 的技巧

  • Time profiler 是一个查看 app 耗时细节的优秀工具
    当 app 发生响应问题,或者当你想要加快 app 启动时间时,使用 time profiler 会是一个很好的选择。
  • 当程序卡死时,优先检查主线程
    主线程只能被用于更新 UI 或者响应用户的输入事件, 比如 Mac 上的鼠标点击或者 iOS 设备上的触摸。如果 app 长时间没有响应,很有可能就是主线程阻塞了。
  • release 配置下进行 profile
    Xcode 编译器支持不同的优化水平,在 debug 模式下会使用低优化水平,而我们通过 App Store 下载到的应用则使用高优化水平。确保在 profile 应用的时候使用的是 release 配置。
  • 在高负荷情况以及老设备上进行 profile
    在这个案例中,苹果工程师在开发过程中并没有遇到这个 bug,但是用户在他们自己的设备上遇到了。 所以如果可能的话,使用老机型来进行 profile。
  • 在模拟器上使用 Instrument 要特别注意
    由于模拟器是在 mac 上运行的,这意味着它有着和 mac 相同的资源竞争管理、cpu 和内存性能、文件管理能力和硬件能力、发热限制等,这和其他设备上的表现会大不相同,需要特别注意。

尽管已经解决了 app 的响应问题,但是 cpu 的过高使用率仍旧没有改善,而过高的CPU使用率会导致

  • 电量消耗过快
  • 设备发热
  • mac 上的风扇转速过快

接下来,需要通过 signpost 来更深入的了解 app 运行情况,并解决 cpu 使用率过高的问题。

使用 Signposts

Time profiler 通过观察一段时间内应用的线程和调用栈的相互关系来对代码进行静态分析。但它无法精确测算代码是怎样执行的。如下图所示,一段代码可能会在一段时间内执行多次,也可能只执行几次, 甚至某些函数可以一直不断地执行来跑满 cpu。为了区分出不同代码的执行模式,需要精确的代码日志。那么如何才能获取这些代码日志呢? 答案就是使用 signpost

SignpostOSLog 家族的新成员,在 WWDC2018 的 session 405 中被提及,具体可以参考Measuring performance using logging

top Created with Sketch.