背景
MindSpore作为新一代深度学习框架,具有动态图灵活、易调试的特点,同时支持图模式执行,提高执行效率。动静结合的方式,加上多组件多后端,其执行流程较为复杂。尤其是静态图模式下,图编译与执行过程是一个黑盒,这给用户跟踪MindSpore执行状态,功能调试带来挑战。
特性简介
为解决跟踪MindSpore的执行状态,提出通过设计状态日志。 识别各组件的关键环节的起始与终止位置,记录状态信息日志,实现执行状态的跟踪。
MindSpore主要的执行流程包括图编译和图执行,其中图编译分为前端编译与后端编译。前端编译是与设备无关的语法解析与优化过程,后端编译是与设备相关的特化过程。
图编译的主要阶段包括如下:
-
parse
:负责解析入口函数,该阶段会初步生成MindIR,如果查看IR文件,我们能观察到该阶段仅仅解析了顶层Cell的图信息; -
symbol_resolve
:负责进一步解析入口函数,主要是递归解析入口函数直接或间接引用到的其他函数和对象。如果使用了尚不支持的语法,一般会在此阶段出错; -
abstract_specialize
:根据输入信息推导出IR中所有节点的数据类型和形状信息; -
optimize
:负责硬件无关的优化,自动微分与自动并行功能也是在该阶段展开。该阶段又可细分为若干个子阶段,算子融合即是在该阶段; -
validate
:负责校验编译出来的计算图,如果到此阶段计算图中还有仅临时使用的内部算子,则会报错退出; -
task_emit
: 负责将计算图传给后端进行后端优化; -
execute
:负责启动执行图流程。
为记录mindspore的编译与执行状态,在任务的开始与结束,计算图的编译与执行各阶段打印格式化日志信息。 格式如下:
Status record: system init.
Status record: start xxx action.
Status record: end xxx action.
...
Status record: start load input. xxx
Status record: end load input. xxx
Status record: start run graph. xxx
Status record: end run graph. xxx
...
Status record: system exit.
system init
表示C++后端初始化。
star xxx action
表示前端编译的各个阶段的开始,如start parse action
,start symbol_resolve action
等等。
end xxx action
表示前端编译的各个阶段的结束,与start xxx action
成对出现。 如end parse action
,end symbol_resolve action
等。
start load input
表示后端开始加载数据进行训练或推理,该信息后面的xxx
表示附加说明信息,例如当前计算图的编号,当有多个计算图时,会分别记录多个计算图的起始状态。
end load input
表示后端加载数据完成。 与start load input
成对出现。附加说明信息中计算图的编号会保持一致,表示同一个计算图执行的开始与结束。
start run graph
表示开始在设备上执行计算图。 附加说明信息中的计算图的编号会与加载数据的图对应。
end run graph
表示完成在设备上执行计算图。 与start run graph
成对出现,附加说明信息中计算图的编号会保持一致,表示同一个计算图执行的开始与结束。
system exit
表示C++后端执行结束。
由于训练过程是一个循环执行,所以start load input
, end load input
,start run graph
与end run graph
状态会打印多次,打印次数与训练的执行模式(是否图下沉)、step以及epoch有关。
在不同的后端图编译过程中,会记录不同的子阶段的执行状态,这些状态主要用于开发者定位问题,用户可以不用过多关注这些状态。
MindSpore执行状态日志级别是INFO,需要设置环境变量GLOG_v=1,并将执行日志落盘到文件,然后通过查询关键字Status record:
筛选出执行状态日志。
例如,在CPU上使用mnist数据集训练lenet,获取执行状态日志的方法如下:
1、设置环境变量,指定日志打印级别为INFO:
export GLOG_v=1
2、执行训练任务,指定数据集路径$DATA_PATH
和保持checkpoints路径$CKPT_PATH
,并落盘日志到文件:
python train.py --data_path=$DATA_PATH --device_target="CPU" --ckpt_path=$CKPT_PATH > log.txt 2>&1 &
3、通过关键字筛选执行状态日志:
grep "Status record:" log.txt > status.txt
如下是CPU上的执行状态日志:
Status record: system init.
Status record: start parse action.
Status record: end parse action.
Status record: start symbol_resolve action.
Status record: end symbol_resolve action.
Status record: start combine_like_graphs action.
Status record: end combine_like_graphs action.
Status record: start inference_opt_prepare action.
Status record: end inference_opt_prepare action.
Status record: start abstract_specialize action.
Status record: end abstract_specialize action.
Status record: start auto_monad action.
Status record: end auto_monad action.
Status record: start inline action.
Status record: end inline action.
Status record: start py_pre_ad action.
Status record: end py_pre_ad action.
Status record: start pipeline_split action.
Status record: end pipeline_split action.
Status record: start optimize action.
Status record: end optimize action.
Status record: start py_opt action.
Status record: end py_opt action.
Status record: start auto_monad_reorder action.
Status record: end auto_monad_reorder action.
Status record: start eliminate_forward_cnode action.
Status record: end eliminate_forward_cnode action.
Status record: start validate action.
Status record: end validate action.
Status record: start task_emit action.
Status record: end task_emit action.
Status record: start execute action.
Status record: end execute action.
Status record: start load input. graph id: 0
Status record: end load input. graph id: 0
Status record: start run graph. graph id: 0
Status record: end run graph. graph id: 0
Status record: start load input. graph id: 0
Status record: end load input. graph id: 0
Status record: start run graph. graph id: 0
Status record: end run graph. graph id: 0
...
...
Status record: system exit.
应用示例
MindSpore执行状态日志方便用户识别当前任务的状态。当出现报错时,可以快速识别出当前的故障模块,有针对性地解决问题。 此外,在多机多卡并行训练的场景下,如果不同进程之间存在执行不同步的问题,用户可以利用执行状态日志快速识别执行慢的结点或进程。 下面通过多进程并行训练场景的故障分析,说明在并行训练场景下状态日志的应用。
场景1 进程意外终止,无system exit状态日志
单机多进程训练场景,一个进程在参数更新阶段会等待其他进程返回梯度信息。当某个进程意外终止退出时,其他进程因等待超时而报错。意外终止进程的INFO日志不会打印退出状态Status record: system exit
。 使用grep命令搜索Status record: system exit
,如果某进程日志不包含该条日志信息,则该进程为异常终止进程,其他进程执行异常由异常终止进程引起。此时,分析线程异常终止的原因即可,如原因不明,可重启训练任务。
场景2 进程退出不同步
多机多进程训练场景,存在一个执行慢的节点。常见的故障场景时编译期不同步,如扩容场景下,新增节点没有编译缓存,其他旧节点存在编译缓存,没有编译缓存的节点会进行图编译,速度慢。有编译缓存的节点直接读取编译缓存,速度快。在所有节点的日志中,使用grep命令搜索Status record: system exit
,每个节点中每个进程的INFO日志都会包含退出状态信息,比较退出状态信息的时间,可以找出退出最早和最晚的进程。退出时间相差500s左右时,可确定晚退出的节点是故障节点。需要注意的是,不同节点的系统时间可能存在差异,需要消除时间基准不同引起的时间差异。 消除差异的方法,可以计算Status record: system exit
与Status record: system init
的时间差,时差最长的节点即为故障节点。