instrument工具 -- Timer profile & Signpost

之前使用instrument工具进行性能检测时，总感觉找不到窍门，要浪费很多时间才能定位到有问题的代码片段。工作的项目中慢慢重视性能优化一块了，所以想着先将instrument了解一遍，上周是先看了头号种子选手 —— Timer profile。

1 性能检测工具使用的原因

2 Timer Profile如何使用

2.1 通用技巧

2.2 signpost

3 总结

1 性能检测工具使用的原因

去年在尝试进行性能优化的工作时根本无从下手，只能不断的从网上找资料，然后跟着资料学着给所有的阴影加个shadowPath、更改所有圆角的绘制方法、以及不断的想怎么减少层级关系等等，虽然这些方法都是已经总结有效的处理，但是如同在2018年WWDC关于如何通往更高效性能中也提到了，性能问题主要可以划分三大场景:

① 性能衰退 Major Regression

某次回归测试的时候突然出现大幅度的性能问题，这时候必须回过头排查新调整代码的逻辑，当然如果工程中有自动化测试功能那么就能直接细致的监控。

② 偏离目标 Off Target

目标性能为页面刷新每秒55帧以上，但是实际却只有45或者更少的帧率。说明存在待解决的几个问题需要进行修复。

③ 拙劣设计 Poor Design

性能表现的极差，给用户的已经不是体验而是考验了...不再只是解决几个问题就能修复了，需要认真的排查架构、页面结构等深一层的问题。

通往高效性能之路

所以真正的性能优化首先要知道自己的方向是哪种场景，针对该场景下采取相对应的手段检测存在的问题。虽然别人的经验确实是有用的，但是得想方设法的找到关键点。

2 Timer Profile如何使用

2.1 通用技巧

Timer Profile界面

打开检测工具的界面时，有几个我在学习时值得注意的地方:

① Detail View

左下角的详细信息中有Weight 和 Self Weight、Symbol Name三列，后面的符号名称比较好理解，前面两个:
Weight表示权重，从这个方法开始耗费总时间的权重
Self Weght表示这个方法本身耗费的时间权重，上图中全是0，表示真正耗时的在内部的调用方法中

② Extended Detail View

右下角的堆栈追踪信息，当选中左边的一项时，右边会迅速的打开整个调用关系堆栈，而灰色标注的是系统方法。

而在寻找耗时方法们的路上有几个挺好的小技巧:

① 快速过滤

过滤系统库并且将耗时的方法置顶

快速过滤

② 快速打开层级关系

点击方法的同时按住option，能快速开启多层

快速开启多层

③ 具体耗时分析

点击某一项时，会进入具体某一行代码的占用权重分析

具体耗时分析

③ 降低检测成本

当检测的数据过多，instrument默认开启的即时记录可能会导致电脑发热卡顿。如果想要在发现性能问题立刻停止调试的话是需要开启即时记录，而其他情况下延迟或者最后5秒的处理已经能满足需求了

降低检测成本

剩下的就是找啊找啊找啊找，这时候如果是自己写的代码逻辑还好，一眼能知道这个方法占比较多的原因，但是如果是别人的代码，你知道是怎么一回事吗？

是时候引入苹果在2018年为OSLog家族引入的性能衡量工具Signpost了。

2.2 signpost

即便在Timer Profile中检测的时候能告诉你是否是方法本身占用耗时，但是却无法判断出到底是因为调用了太多次还是本身方法存在一个超级耗时的操作。而signpost的作用就是告诉你这段代码占用耗时比如此大的具体信息。

signpost

在代码中写入signpost打印的内容会显示到instrument，写入的方法十分简单:

① signpost先导入 os/signpost.h

① 创建os_signpost_interval_begin/end

    os_log_t log = os_log_create("com.lizhou.WorkIdeaDemo", "third");
    os_signpost_id_t signid = os_signpost_id_generate(log);
    os_signpost_interval_begin(log, signid, "outerTotal");
    for(int i = 0; i < 100000; i++) {
       
        os_signpost_interval_begin(log, signid, "signpost");
        NSLog(@"打印的第%d遍",i);
        os_signpost_interval_end(log, signid, "signpost");
        
    }
    os_signpost_interval_end(log, signid, "outerTotal");

以上的逻辑可以分为三步进行了解:

① os_log_t

os_log_t os_log_create(const char *subsystem, const char *category);

subsystem自定义的标识符，可以直接使用项目的bundle id
category是用于分类，主要作用于对相关联的内容操作进行分类

② os_signpost_id_t

os_signpost_id_t os_signpost_id_generate(os_log_t log);

③ begin/end

记录一段代码逻辑执行的情况就是从开始到结束，

os_signpost_interval_begin(log, interval_id, name, ...) 
os_signpost_interval_end(log, interval_id, name, ...)

begin/end的name一致，保证能识别出是同一个逻辑的开始/结束，后面的…表示能添加额外的参数，在instrument中显示。

当插入以上逻辑后进行检测会显示以下的内容: 代码的执行次数、时长以及每次执行时最大、最短和平均时长等内容

os_signpost打印内容

当然在实际开发中会更多的需要检测异步线程中的性能问题，注意一下上图中的显示: 只使用了os_log的category 和 os_signpost的name进行分类，并没有使用interval_id。解释一下三种分类字段的含义就能清楚的明白:
category 相关操作
signpost name 某类相同操作
signpost id 同一类型操作下的不同任务
所以异步其实就是相同类型操作下创建了多个不同的任务，只要三个标识相同的begin/end成对出现，那么在不同的线程中都可以进行检测。

for(int i = 0; i < 10; i++) {
        os_signpost_id_t signid_1 = os_signpost_id_make_with_pointer(log, (__bridge const void * _Nullable)([NSString stringWithFormat:@"%d",i]));
        os_signpost_interval_begin(log, signid_1, "signpost");
        dispatch_async(dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_DEFAULT, 0), ^{
            NSLog(@"打印的第%d遍",i);
            os_signpost_interval_end(log, signid_1, "signpost");
        });
        
    }

如果想要在begin和end间添加一些特定的点，比如用户的点击事件和图片在某个特定时间点的加载信息，就能使用event事件

    os_log_t log = os_log_create("com.lizhou.WorkIdeaDemo", OS_LOG_CATEGORY_POINTS_OF_INTEREST);
    os_signpost_id_t signid = os_signpost_id_generate(log);
    os_signpost_event_emit(log, signid, "点击事件","点击第%ld个",index);

每个事件的name后都能添加additional information，比如上面的动态字符串格式
os_signpost如何添加到points of interest区块中，请看上图的os_log_t创建方法中的category

看一下instrument的显示格式，按照分类逻辑显示清晰明了：

instrument检查结果界面

聊了这么多如何使用signpost，最重要的一件事还没聊: 什么时候可以去使用？

① 禁止与开启log

虽然signpost本身是轻量级的，而且为编译时做了大量的优化，把大部分工作推迟到instrument中。但是release包确实没有必要开启,直接为log赋值disable

② 使用版本

API_AVAILABLE(macos(10.12), ios(10.0), watchos(3.0), tvos(10.0))
OS_EXPORT OS_NOTHROW OS_WARN_RESULT OS_OBJECT_RETURNS_RETAINED OS_NONNULL_ALL
os_log_t
os_log_create(const char *subsystem, const char *category);

API_AVAILABLE(macos(10.14), ios(12.0), tvos(12.0), watchos(5.0))
OS_EXPORT OS_NOTHROW OS_WARN_RESULT
os_signpost_id_t
os_signpost_id_generate(os_log_t log);

当在低版本中使用这些字段时，直接崩溃打印以下的报错信息:

lazy symbol binding failed: Symbol not found: _os_signpost_id_generate

学习的过程中真的发现很多有意思的地方，但是也发现了一些还未解决的部分，通往高性能的路上还需要继续学习。