性能分析工具——os_signpost

1. os_signpost是什么

signpost这个单词是路标、指示牌的意思,比如距离北京还有158km。顾名思义,os_signpost就是在代码里面插入一些标记,作用相当于路标。官方文档是这样描述的:

The os_signpost APIs let clients add lightweight instrumentation to
code for collection and visualization by performance analysis tooling.

用人话说就是:os_signpost是一个轻量级的可视化的性能分析工具。

2. os_signpost的提出背景

代码层面的性能分析,最直观的方式就是标识出一段代码的开始和结尾,然后计算下耗时。就像下面这样:

CFTimeInterval begin = CACurrentMediaTime();
// do something 
CFTimeInterval end = CACurrentMediaTime();
NSLog(@"cost = %@",(end - begin));

然而如果代码逻辑复杂、有先后关系、存在多个线程等,单靠某小段代码的标记,就不是那么直观了。

于是,在2018年9月,苹果推出了os_signpost,它可以配合Instruments,显示可视化的效果,WWDC视频Measuring Performance Using Logging有介绍。因为是18年才推出,所以os_signpost只支持iOS12及以上系统,Xcode10及更高版本。

3. os_signpost的用法

这里以OC代码为例。

(1) 先导入头文件,为了使用方便,再定义两个宏:
#include <os/signpost.h>

#define INNER_BEGIN_LOG(subsystem, category, name) \
os_log_t m_log_##name = os_log_create((#subsystem), (#category));\
os_signpost_id_t m_spid_##name = os_signpost_id_generate(m_log_##name);\
os_signpost_interval_begin(m_log_##name, m_spid_##name, (#name));

#define INNER_END_LOG(name) \
os_signpost_interval_end(m_log_##name, m_spid_##name, (#name));

这两个宏是成对使用的,这段代码可以放公共的头文件里,方便不同的地方用。

(2)给代码插入路标:

页面初始化的时候插入名字为init的标记,
viewDidAppear的时候插入名字为viewDidAppear的标记,
接口请求回调时插入名字为requestDidCompleted的标记,
数据处理完插入名字为requestProcessComplete的标记。

- (id)init {
    self = [super init];
    if (self) {
        if (@available(iOS 12.0, *)) {
            INNER_BEGIN_LOG(fourPage, init, init);
            INNER_END_LOG(init);
        }
        // do something
    }
    return self;
}

- (void)viewDidAppear:(BOOL)animated {
    [super viewDidAppear:animated];
    // do something
    if (@available(iOS 12.0, *)) {
        INNER_BEGIN_LOG(fourPage, init, viewDidAppear);
        INNER_END_LOG(viewDidAppear);
    }
}

- (void)requestDidCompleted {
    if (@available(iOS 12.0, *)) {
        INNER_BEGIN_LOG(fourPage, init, requestDidCompleted);
        INNER_END_LOG(requestDidCompleted);
    }
    // do something
    if (@available(iOS 12.0, *)) {
        INNER_BEGIN_LOG(fourPage, init, requestProcessComplete);
        INNER_END_LOG(requestProcessComplete);
    }
}
(3)工程设置

Debug Information Format设置为DWARF with dSYM File,如下图所示:

工程设置.png

这一步是为了后面在Instruments里面能直接看到代码。
现在就可以插上手机跑起来了。

(4)配合Instruments

打开Instruments的Time Profiler,默认会有一行Points of Interest,这里用不到,可以把它删了,选中再按删除键即可。然后添加os_signpost,如下图所示:
添加os_signpost.png

把这个模板保存起来,点上面的File->Save As Template...,输入名字signpost。

下次就可以直接从Instruments里打开这个自定义模板了:
自定义模板.png

选择刚刚跑的app,点左上角的红色按钮开始录制,这时候界面显示Recording,操作完了再次点左上角按钮结束录制,然后进入下面这样的界面:
Instruments_1.png

刚录制完可能看不到刚刚插入的那些标记,只要在上图中红线位置往下拖,把界面展开就看到了,如下图所示。左边红框就是添加的4个标记,右边红框里的竖线是相应的时间。把鼠标放在右边红框位置,滚动滚轮,可以缩放时间轴,笔记本用户可以用触摸板缩放。
Instruments_2.png

时间轴放大后可以清晰地看到,从init到viewDidApper整个过程耗时840ms,其中接口请求耗时405ms,接口解析耗时35ms,页面渲染耗时400ms,还可以看到这段时间主线程压力很大。

到这就可以分析一下具体哪些代码耗时了。在下图1位置选Samples,就是对代码采样,在2位置消耗CPU较严重的区域点击,然后在3位置就可以看到该位置对应的代码,如果前面Debug Information Format没有设置的话,这里是看不到代码的。
Instruments_3.png

以我的代码为例,可以计算出onlineChatBtn加载图片用了48ms,而它的父视图初始化用了305ms,这些都是在主线程执行的。

4. 小结

通过以上这些操作,我们能够看到两个标记之间具体执行了哪些代码,以及哪些代码比较耗时,进而可以有针对性地进行优化。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,271评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,275评论 2 380
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,151评论 0 336
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,550评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,553评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,559评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,924评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,580评论 0 257
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,826评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,578评论 2 320
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,661评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,363评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,940评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,926评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,156评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,872评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,391评论 2 342