网络模型训练性能分析案例

背景介绍

以TensorFlow网络基础框架的堆叠沙漏网络模型为例执行训练，发现该模型在GPU上的迭代耗时为310 ms，而在昇腾AI处理器上的迭代耗时达到360 ms，昇腾AI处理器慢了50 ms。通过执行Profiling性能分析，寻找昇腾平台训练迭代耗时高的原因，发现问题在于AI CPU中dropout算子的随机数函数耗时较大。通过查看并修改用户脚本的drop脚本，重新测试性能后迭代端到端的性能得到了提升。

前提条件

性能数据采集和解析操作

通过以下操作方法执行性能数据采集：

  1. 以Ascend-cann-toolkit开发套件包的运行用户登录环境。以HwHiAiUser用户为例。进入用例路径。 

    cd ${data_path}

  2. 通过设置环境变量方式，开启Profiling数据采集功能。配置的环境变量内容示例如下。

    1. 设置环境变量，增加Profiling的配置。 
      export PROFILING_MODE=true
export PROFILING_OPTIONS='{"output":"/home/HwHiAiUser/profiler_data","storage_limit": "500MB","training_trace":"on","task_trace":"on","aicpu":"on","fp_point":"","bp_point":"","aic_metrics":"PipeUtilization"}'
    2. 使设置生效。

      详细的使用及参数解释，请参见使用环境变量采集和Profiling options参数解释。

  3. 执行训练操作。示例如图1所示。

    图1 执行训练

    执行命令后等待训练完成。

    有关TensorFlow模型训练详细介绍请参见《TensorFlow 1.15模型迁移指南》。

  4. 解析Profiling数据。

    执行如下命令，解析并导出性能数据。 
    msprof --export=on --output=/home/HwHiAiUser/profiler_data

    执行完上述命令后，会在PROF_XXX目录下生成mindstudio_profiler_output目录。

问题定位

  1. 迭代耗时分析。

    通过解析性能数据可得到迭代轨迹数据step_trace_*.json。在Chrome浏览器中输入“chrome://tracing”地址，将迭代轨迹数据step_trace_*.json拖到空白处进行打开，通过键盘上的快捷键（w：放大，s：缩小，a：左移，d：右移），查看每次迭代的耗时情况。timeline数据展示如下。

    图2 迭代总耗时
    图3 FP+BP耗时
    从图2中可以看到迭代训练的总耗时为561.827 ms，其中FP+BP耗时为561.599 ms，FP+BP耗时可从图3中得到，FP+BP耗时占总耗时的99.9%，两者差异部分为Iteration Refresh（迭代更新拖尾）。step_trace_*.json对应的summary文件为step_trace_*.csv，打开该文件后如下图所示。
    图4 step_trace_*.csv

    基于以上数据可知，Iteration Refresh（迭代更新拖尾）部分耗时比算子FP+BP耗时小很多，不存在性能瓶颈，也就是说该模型训练耗时长不是由性能瓶颈导致。那么我们需要接着分析算子的耗时。

  2. 算子耗时分析。

    1. AI Core数据op_summary_*.csv。该文件统计的是某个迭代下（默认为1），bp_point + fp_point整个链路的算子耗时具体情况。在这个文件中，着重看Task Duration列，它记录着当前算子的耗时。可以通过表格中的自定义排序，选择Task Duration为主要关键字，进行降序重排表格，开头部分截图如下。可见，当前网络中涉及的算子，最大耗时仅231.54us。如图5所示。
      图5 op_summary

      从该表中依旧无法判断耗时较长的原因，那么继续打开AI Core算子调用次数及耗时数据。

    2. AI Core算子调用次数及耗时数据op_statistic_*.csv。该文件是对bp_point + fp_point整个链路上算子，不区分OP Name，按算子的OP Type做了统计。比如将 Mul 算子统计为一行，统计调用次数、总耗时、平均耗时、最大耗时、最小耗时等。通过表格中的自定义排序，选择Ratio(%)为主要关键字，进行降序重排表格，截图如下。可见，AI CPU在整体耗时占比达到76.5%。如图6所示。
      图6 op_statistic
    3. 问题定位到了AI CPU耗时上，那么我们查看aicpu_*.csv文件。通过表格中的自定义排序，选择Total_time为主要关键字，进行降序重排表格，截图如下。可以看到在AI CPU中耗时最大的是dropout算子中的随机数函数，且已经达到了毫秒级别。如图7所示。
      图7 aicpu

    到此Profiling性能分析工具的任务已经完成。

问题解决

  1. 查看用户脚本，发现用户脚本中的drop脚本使用的是TensorFlow的原生脚本。

    TensorFlow框架的模型在昇腾AI处理器训练时需要先完成迁移操作，详细操作请参见《TensorFlow 1.15模型迁移指南》中的“手工迁移”章节。

  2. 我们通过修改训练脚本将dropout接口替换成昇腾优化过的drop脚本。如图8所示。

    图8 修改训练脚本

  3. 重新测试性能后迭代端到端的性能提升从360 ms提升到了47 ms。如图9所示。

    图9 迭代端到端性能耗时

结论

通过Profiling性能分析工具对模型训练的迭代端到端性能进行分析，定位到耗时最长的算子，通过修改训练脚本，最终提升了模型在昇腾AI处理器的训练性能。

父主题： 性能分析案例