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

背景介绍

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

前提条件

操作系统：Ubuntu18.04

Profiling性能分析操作

执行以下操作前请参见环境搭建完成环境搭建。

通过以下操作方法执行Job Profiling：

  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数据。

    1. 切换至msprof.py脚本所在目录，如/home/HwHiAiUser/Ascend/ascend-toolkit/latest/tools/profiler/profiler_tool/analysis/msprof。

      小技巧：为方便执行msprof.py脚本，您可以使用HwHiAiUser用户执行命令alias msprof='python3 /home/HwHiAiUser/Ascend/ascend-toolkit/latest/tools/profiler/profiler_tool/analysis/msprof/msprof.py'设置别名，后续就可以不用进入/home/HwHiAiUser/Ascend/ascend-toolkit/latest/tools/profiler/profiler_tool/analysis/msprof目录，在任意目录输入msprof即可执行Profiling命令。该操作仅在当前窗口下生效。

    2. 执行如下命令，解析任意目录的Profiling数据。
      python3 msprof.py import -dir /home/HwHiAiUser/profiler_data

    此处仅以import方式为例执行解析，详细操作请参见数据解析与导出。

  5. 在msprof.py脚本所在目录继续执行如下命令导出timeline数据。

    python3 msprof.py export timeline -dir /home/HwHiAiUser/profiler_data

    执行完上述命令后，会在collection-dir目录下的PROF_XXX目录下生成timeline目录，目录中生成对应的json文件，如图2所示，具体内容参见Profiling数据说明。

    图2 timeline目录

  6. 在msprof.py脚本所在目录继续执行如下命令导出summary数据。

    python3 msprof.py export summary -dir /home/HwHiAiUser/profiler_data --format csv

    执行完上述命令后，会在collection-dir目录下的PROF_XXX目录下生成summary目录，目录中生成对应的csv文件，如图3所示，具体内容参见Profiling数据说明。

    图3 summary目录

问题定位

  1. 迭代耗时分析。

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

    图4 迭代总耗时
    图5 FP+BP耗时

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

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

  2. 算子耗时分析。

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

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

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

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

问题解决

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

    TensorFlow框架的模型在Atlas 训练系列产品训练时需要先完成迁移操作，详细操作请参见《TensorFlow 1.15网络模型迁移和训练指南》中的“手工迁移和训练”章节。

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

    图9 修改训练脚本

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

    图10 迭代端到端性能耗时

结论

通过Profiling性能分析工具对模型训练的迭代端到端性能进行分析，定位到耗时最长的算子，通过修改训练脚本，最终提升了模型在Atlas 训练系列产品的训练性能。

父主题： 性能数据分析