SkyWalking8源码（四）性能剖析（Profiling）分析SkyWalking如何实现性能剖析（profilin

前言

本章基于8.6.0版本，分析性能剖析（profiling）特性：

1. ui页面创建剖析任务参数的含义；
2. 在oap创建剖析任务如何通知agent；
3. agent如何采样segment进行profile；
4. oap如何分析agent上报的栈快照；

使用案例

业务代码：暴露/api/slow接口，内部调用3个方法，方法内部只是睡眠n毫秒。

@GetMapping("/api/slow")  
public String slow() {  
    fastMethod(); // sleep 100ms  
    slowMethod1(); // sleep 1000ms  
    slowMethod2(); // sleep 1500ms  
    return "ok";  
}

通过SkyWalking页面发起性能剖析任务。 向/api/slow注入流量收集数据。 查看采样trace的线程堆栈，有四个字段：

1）ThreadStack：方法栈；

2）Duration：方法总耗时；

3）Self Duration：方法自身耗时（不包含内部其他方法）；

4）Dump Count：方法栈被采集到的次数； 通过方法栈分析，可以定位到具体的慢方法，如slowMethod1和slowMethod2。

一、OAP新建profile任务

ProfileTaskMutationService#createTask：Step1，入参校验。对于一个服务，在监控时间范围内，只能存在一个任务。 ProfileTaskMutationService#createTask：Step2，封装为ProfileTaskRecord直接落库。 注意，timebucket是任务监控结束时间。 NoneStreamPersistentWorker#in：对于NoneStream类型模型调用DAO服务存储。 如采用ElasticSearch存储，数据结构如下：

二、Agent拉取profile任务

ProfileTaskChannelService：

1）实现GRPCChannelListener，监听与OAP连接的变更，因为需要与OAP通讯；

2）实现BootService，启动后发起定时任务（可通过profile.active=false关闭），每20s（collector.get_profile_task_interval）从OAP拉取任务； ProfileTaskChannelService#run：agent发送ProfileTaskCommandQuery，包含service信息和已有task的创建时间。

三、OAP返回profile任务

ProfileTaskServiceHandler#getProfileTaskCommands：oap查询task响应agent

1）根据agent的service，查询ProfileTask集合，走内存缓存；

2）循环处理ProfileTask，根据agent请求中的task创建时间过滤，对于被拉取到的task记录serviceInstance级别日志；

任务缓存

ProfileTaskCache使用guava本地缓存，缓存每个service对应的task列表，容量是1w个service。 CacheUpdateTimer#updateProfileTask：CacheUpdateTimer每隔10s刷新一次缓存。 每次查询未来25分钟内结束的task，按照service分组放入缓存。 ProfileTaskQueryEsDAO#getTaskList：注意查询字段timebucket是监控结束时间。 ProfileTaskCache#saveTaskList：缓存更新，直接替换service下的task。

任务日志

ProfileTaskServiceHandler#recordProfileTaskLog：对于某个instance拉取到task，记录task日志，状态为NOTIFIED。 如使用ElasticSearch存储。

四、Agent开始profile

提交profile任务

CommandService#receiveCommand：agent收到oap响应数据，循环放入commands阻塞队列（容量64）。 CommandService#run：commands由CommandService单线程消费，调用不同的command处理器处理。 ProfileTaskCommandExecutor#execute：ProfileTaskCommandExecutor处理profile任务。 ProfileTaskExecutionService#addProfileTask：计算profile启动时间，放入调度线程池（1线程）。 ProfileTaskExecutionService#processProfileTask：当到达监控开始时间，执行profile

1）stopCurrentProfileTask，先停止目前存在正在执行的profile任务（oap控制一个时间范围内一个service只能存在一个profile任务，这里概率不大）；

2）构造ProfileTaskExecutionContext代表profile任务上下文，传入profile线程池（单线程），开始profile；

3）提交延迟任务，当profile任务时间结束，执行停止profile逻辑； ProfileTaskExecutionContext#startProfiling：提交ProfileThread开始执行profile。 ProfileThread#profiling：一个无限循环任务，每隔监控间隔，执行一次线程栈采集。

Segment采样

在创建profile任务时，确定了对哪个端点执行profile，比如/api/slow。 Profile线程需要dump哪些线程的栈，需要从Segment关联采样。 Segment关联Profile的入口有两处。 case1，segment创建时，将第一个operationName作为端点匹配。（往往是第一次创建EntrySpan） case2，EntrySpan覆盖时，用新的operationName再次校验是否要关联profile。

注：第一章说到过EntrySpan覆盖的问题，由于入口流量会经过多个插件，operationName取最后经过的插件的operationName。如低版本中tomcat和mvc插件的operationName不同，mvc会覆盖tomcat的operationName，使用profile无论用tomcat的接口名，如/api/slow，还是用mvc的接口名，如{GET}/api/slow，都能生效。

ProfileTaskExecutionService#addProfiling/profilingRecheck：如果当前存在profile任务，尝试将当前segment关联到profile，recheck的区别是校验了针对当前segment是否已经开启了profile。 ProfileTaskExecutionContext#attemptProfiling：针对当前segment尝试进行profile

1）currentProfilingCount限制，默认最多允许5（profile.max_parallel）个segment并行进行profile；

2）端点匹配；

3）maxSamplingCount限制，由profile任务创建时限制的最大采样数，实际限制的是采样segment数量；

4）cas竞争更新currentProfilingCount，如果成功才继续执行；

5）创建ThreadProfiler，包含trace和当前线程；

6）cas尝试将ThreadProfiler放入ProfileTaskExecutionContext的slots数组，如果放入成功则进行profile，放入失败则放弃profile；

执行profile

ProfileThread#profiling：回到Profile线程，这里可以拿到需要做profile的ThreadProfiler（segment和所在线程）。 ProfileThread#profiling：ThreadProfiler有两种状态

1）PENDING：ThreadProfiler刚构造，segment刚加入profile任务，未开始profile；

2）PROFILING：通过startProfilingIfNeed决策，开始profile； ThreadProfiler#startProfilingIfNeed：决策针对当前segment是否开始profile，需要segment创建超过minDurationThreshold时间。 minDurationThreshold由任务创建决定，对应起始监控时间，默认0ms，只要segment创建，就可以开始profile获取栈快照。 ThreadProfiler#buildSnapshot：针对一个segment构建线程栈快照。

1. isProfilingContinuable，一个segment最多profile 10分钟；
2. profilingThread#getStackTrace，获取segment关联Thread当前的栈；
3. executionContext#isStartProfileable，首次记录segment栈快照，累加总采样数，如果超出最大采样数则直接结束；
4. 默认最多从栈顶采集500深度（profile.dump_max_stack_depth）；

上报线程快照

ProfileThread#profiling：采集线程栈后，需要上报数据到oap。 ProfileTaskChannelService#addProfilingSnapshot：先放入阻塞队列，容量500（profile.snapshot_transport_buffer_size）。

注意这里是阻塞队列的add方法，如果塞满了会报错，直接中断本次profile任务。

ProfileTaskChannelService#boot：agent启动时开启独立线程，每500ms将栈快照上报OAP。

五、OAP记录线程快照

ProfileTaskServiceHandler#collectSnapshot：oap收集线程快照，线程栈将以byte数组方式存储，同Segment下的Span。 如用ElasticSearch存储如下：

六、Agent停止Profile

Segment停止Profile

Segment停止Profile有两种方式：

1. 到达10分钟阈值，由Profile线程自动停止；（见上面Agent执行profile，已分析）
2. Segment结束，由业务线程停止； TracingContext#finish：当所有span都出栈后，segment结束，TracingThreadListenerManager可以通知到Profile服务。 ProfileTaskExecutionService#afterMainThreadFinish：如果当前segment关联了profile，且profile任务正在执行，则通过profile任务上下文停止profile。 ProfileTaskExecutionContext#stopTracingProfile：循环所有slot，通过traceId匹配ThreadProfiler，移除ThreadProfiler并减少并行segment计数。

停止Profile任务

ProfileTaskExecutionService#processProfileTask：提交profile任务时，根据task持续时间提交了延迟任务，用于停止profile任务。 ProfileTaskExecutionService#stopCurrentProfileTask：停止profile任务，主要是资源清理，最终通知oap本次profile任务结束。 ProfileTaskChannelService#notifyProfileTaskFinish：告知oap本次profile任务结束。

七、OAP记录profile任务结束

ProfileTaskServiceHandler#reportTaskFinish：和OAP返回profile任务时一样，记录profile任务日志，状态为EXECUTION_FINISHED。 如控制台展示：

八、OAP分析线程快照

profile上报的都是线程栈的快照，而ui展示字段包含：

1）Self Duration：方法自身耗时；

2）Duration：方法整体耗时；

3）DumpCount：方法被采样次数； 这些分析工作都是点击分析时，实时计算n个线程快照得到的。 ProfileAnalyzer#analyze：

1）getAllSequenceRange：根据时间范围和segmentId，按照500一批切成n批快照（根据快照序号sequence分成n个区间）；

2）queryRecords：分批多线程查询栈快照；

3）analyze：执行分析； ProfileAnalyzer#analyze：入参是n次快照，最终按照stack的root分组合并。 ProfileStack，sequence-快照序号，dumpTime-快照时间，stack-栈。 分析逻辑都在ProfileAnalyzeCollector中。 这里分析逻辑较为复杂，可以参考docs/en/guides/backend-profile.md中的描述。 大致理解为两步：1）将n次快照线程栈合并为一个树；2）计算每个方法的耗时。 主要在于方法耗时如何统计。

ProfileStackNode#buildAnalyzeResult：方法耗时统计，先计算方法总耗时，再计算方法自身耗时； 分析是针对某个segment，拍摄快照按照10ms一次算，合并后的树如下： ProfileStackNode#calculateDuration：方法总耗时Duration=连续快照时间间隔之和。 ProfileStackNode#calculateDurationExcludeChild：方法自身耗时Self Duration=当前方法总耗时-子方法总耗时。

九、异步Segment Profile

在8.15版本后，SkyWalking Agent支持异步Segment Profile。

Support keep trace profiling when cross-thread.

TracingContext#capture：父线程Segment创建ContextSnapshot包含了profile状态上下文。 TracingContext#continued：子线程Segment根据snapshot情况，选择继续profile。 ProfileStatusContext#continued：同一个父Segment下最多并行5（profile.max_accept_sub_parallel）个profile，即如果父线程开6个线程并发处理6个任务，其中有1个线程下的任务无法profile。 注意，子线程profile并不占用profile任务最大采样数，只受客户端并发数约束。 ProfileTaskExecutionContext#continueProfiling：如果当前profile任务在运行，就将子线程封装为ThreadProfiler加入slot，后续流程与正常profile一致。

总结

profile任务创建与通知

创建Profile任务参数可以分为两部分：任务相关、Segment相关。 任务相关：

1）监控时间：profile任务开始时间；

2）监控持续时间：profile任务结束时间；

3）监控间隔：profile任务运行时，线程睡眠间隔，时间间隔短，采集线程栈越多分析越精确，但对宿主应用影响越大；

4）最大采样数：profile任务总共采集segment数量； Segment相关：

5）端点名称：EntrySpan的operationName，如果入口流量经过多个插件，如tomcat和mvc，用哪个operationName都可以匹配到Segment；

6）起始监控时间：对于被采样的segment，在segment创建后多久开始获取线程快照，一般0ms； Agent获取profile任务采用拉的方式，流程如下：

1）OAP：用户通过页面创建profile任务，OAP将数据落库；

2）OAP：每10s，将库中结束时间在25分钟内的任务加载到内存缓存；

3）Agent：每20s，根据服务名和当前agent已收到的任务创建时间戳，从oap拉取任务；

4）OAP：走本地缓存查询service下的任务列表；

5）OAP：如果查询到任务，记录profile任务日志，对于当前Agent ServiceInstance，该profile任务状态为NOTIFIED；

6）Agent：收到OAP返回的profile任务集合，继续后续操作；

profile任务执行

Agent收到profile任务后：

1）将任务放入profile调度线程，延迟到任务开始时间后提交到profile线程；

2）profile线程：循环所有被采样的segment（ThreadProfiler)，针对每个segment获取segment所在线程快照，放入阻塞队列；

3）快照发送线程：每500ms获取阻塞队列中的栈快照发送至OAP；

4）当任务到达结束时间，profile调度线程取消profile线程任务，并通知oap任务结束，oap记录profile任务日志，状态为EXECUTION_FINISHED；

profile线程扫描的Segment，来源于Segment采样，创建Segment和EntrySpan时都会尝试采样：

1）并行数限制：默认最多允许5（profile.max_parallel）个segment并行进行profile；

2）端点匹配：一般是EntrySpan的operationName；

3）最大采样数限制：由profile任务创建时指定，限制总共采样的segment数量；

4）并发限制：同一个端点发生并发segment采样决策，由于各种cas操作，最终只会有一个segment被采样；

5）每个被采样Segment，封装为ThreadProfiler，包含trace和当前线程，提交到profile线程处理；

6）当Segment结束（自然结束或segment执行超过10分钟），将ThreadProfiler从profile线程中移除；

profile分析

Agent上报被采样segment的线程栈快照，oap侧需要将线程栈快照聚合后提供如下指标：

1）Self Duration：方法自身耗时；

2）Duration：方法整体耗时；

3）DumpCount：方法被采样次数；

分析工作由用户在ui页面上点击分析触发，主要包括两方面工作：

1）将n个线程栈快照，合并为一颗树；

2）针对树上每个方法调用，计算总调用数、整体耗时、自身耗时； 总调用数=当前方法关联多少快照； 整体耗时=连续快照id间的时间总间隔； 自身耗时=整体耗时-子方法整体耗时；